Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

StackWalker takes suspiciously long during getLogger call #597

Open
hiddenalpha opened this issue Jun 17, 2024 · 0 comments
Open

StackWalker takes suspiciously long during getLogger call #597

hiddenalpha opened this issue Jun 17, 2024 · 0 comments

Comments

@hiddenalpha
Copy link
Member

hiddenalpha commented Jun 17, 2024

Stumbled over this log below. Is this maybe related to stackoverflow.com/questions/46236326/log4j-slow-initialization or
stackoverflow.com/questions/42830383/logmanager-getlogger-stalls-application
?

Cannot yet make much sense out of it. But to me I cannot get why something as "StackWalker.callStackWalk" needs to be called during a "getLogger()" call.

2024-06-17T16:59:30,630 int houston WARN BlockedThreadChecker - Thread Thread[vert.x-eventloop-thread-2,5,main] has been blocked for 177 ms, time limit is 8 ms
io.vertx.core.VertxException: Thread blocked
        at java.util.stream.AbstractPipeline.wrapSink(AbstractPipeline.java:522) ~[?:?]
        at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
        at java.util.stream.FindOps$FindOp.evaluateSequential(FindOps.java:150) ~[?:?]
        at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
        at java.util.stream.ReferencePipeline.findFirst(ReferencePipeline.java:543) ~[?:?]
        at org.apache.logging.log4j.util.StackLocator.lambda$getCallerClass$2(StackLocator.java:57) ~[log4j-api-2.19.0.jar:2.19.0]
        at org.apache.logging.log4j.util.StackLocator$$Lambda$26/0x0000000840088840.apply(Unknown Source) ~[?:?]
        at java.lang.StackStreamFactory$StackFrameTraverser.consumeFrames(StackStreamFactory.java:534) ~[?:?]
        at java.lang.StackStreamFactory$AbstractStackWalker.doStackWalk(StackStreamFactory.java:306) ~[?:?]
        at java.lang.StackStreamFactory$AbstractStackWalker.callStackWalk(Native Method) ~[?:?]
        at java.lang.StackStreamFactory$AbstractStackWalker.beginStackWalk(StackStreamFactory.java:370) ~[?:?]
        at java.lang.StackStreamFactory$AbstractStackWalker.walk(StackStreamFactory.java:243) ~[?:?]
        at java.lang.StackWalker.walk(StackWalker.java:498) ~[?:?]
        at org.apache.logging.log4j.util.StackLocator.getCallerClass(StackLocator.java:51) ~[log4j-api-2.19.0.jar:2.19.0]
        at org.apache.logging.log4j.util.StackLocatorUtil.getCallerClass(StackLocatorUtil.java:104) ~[log4j-api-2.19.0.jar:2.19.0]
        at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:56) ~[log4j-slf4j2-impl-2.19.0.jar:2.19.0]
        at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:47) ~[log4j-api-2.19.0.jar:2.19.0]
        at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:33) ~[log4j-slf4j2-impl-2.19.0.jar:2.19.0]
        at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:358) ~[slf4j-api-2.0.1.jar:2.0.1]
        at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:383) ~[slf4j-api-2.0.1.jar:2.0.1]
        at org.swisspush.gateleen.core.http.RequestLoggerFactory.getLogger(RequestLoggerFactory.java:45) ~[gateleen-core-2.1.8.jar:?]
        at org.swisspush.gateleen.core.http.RequestLoggerFactory.getLogger(RequestLoggerFactory.java:19) ~[gateleen-core-2.1.8.jar:?]
        at org.swisspush.gateleen.routing.Forwarder.handle(Forwarder.java:125) ~[gateleen-routing-2.1.8.jar:?]
        at org.swisspush.gateleen.hook.Route.forward(Route.java:236) ~[gateleen-hook-2.1.8.jar:?]
        at org.swisspush.gateleen.hook.Route.forward(Route.java:252) ~[gateleen-hook-2.1.8.jar:?]
        at org.swisspush.gateleen.hook.HookHandler.routeRequestIfNeeded(HookHandler.java:728) ~[gateleen-hook-2.1.8.jar:?]
        at org.swisspush.gateleen.hook.HookHandler.handle(HookHandler.java:583) ~[gateleen-hook-2.1.8.jar:?]
        at ch.post.it.paisa.houston.process.main.MainVerticle.lambda$createRouter$4(MainVerticle.java:643) ~[houston-process-02.01.63.00.jar:?]
        at ch.post.it.paisa.houston.process.main.MainVerticle$$Lambda$1537/0x0000000840786c40.handle(Unknown Source) ~[?:?]
        at org.swisspush.gateleen.security.authorization.Authorizer.authorize(Authorizer.java:142) ~[gateleen-security-2.1.8.jar:?]
        at ch.post.it.paisa.houston.process.main.MainVerticle.lambda$createRouter$5(MainVerticle.java:606) ~[houston-process-02.01.63.00.jar:?]
        at ch.post.it.paisa.houston.process.main.MainVerticle$$Lambda$1296/0x00000008406fdc40.handle(Unknown Source) ~[?:?]
        at org.swisspush.gateleen.core.http.LocalHttpClientRequest.ensureBound(LocalHttpClientRequest.java:744) ~[gateleen-core-2.1.8.jar:?]
        at org.swisspush.gateleen.core.http.LocalHttpClientRequest.write(LocalHttpClientRequest.java:760) ~[gateleen-core-2.1.8.jar:?]
        at org.swisspush.gateleen.core.http.LocalHttpClientRequest.end(LocalHttpClientRequest.java:802) ~[gateleen-core-2.1.8.jar:?]
        at io.vertx.core.http.HttpClientRequest.send(HttpClientRequest.java:429) ~[vertx-core-4.5.1.jar:4.5.1]
        at org.swisspush.gateleen.queue.queuing.QueueProcessor.lambda$executeQueuedRequest$10(QueueProcessor.java:293) ~[gateleen-queue-2.1.8.jar:?]
        at org.swisspush.gateleen.queue.queuing.QueueProcessor$$Lambda$1517/0x000000084077f040.handle(Unknown Source) ~[?:?]
        at io.vertx.core.impl.future.SucceededFuture.onComplete(SucceededFuture.java:81) ~[vertx-core-4.5.1.jar:4.5.1]
        at org.swisspush.gateleen.queue.queuing.QueueProcessor.executeQueuedRequest(QueueProcessor.java:240) ~[gateleen-queue-2.1.8.jar:?]
        at org.swisspush.gateleen.queue.queuing.QueueProcessor.lambda$startQueueProcessing$2(QueueProcessor.java:98) ~[gateleen-queue-2.1.8.jar:?]
        at org.swisspush.gateleen.queue.queuing.QueueProcessor$$Lambda$1298/0x00000008406fc040.handle(Unknown Source) ~[?:?]
        at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:276) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.MessageConsumerImpl.dispatch(MessageConsumerImpl.java:177) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.HandlerRegistration$InboundDeliveryContext.execute(HandlerRegistration.java:137) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.DeliveryContextBase.next(DeliveryContextBase.java:80) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.DeliveryContextBase.dispatch(DeliveryContextBase.java:43) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.HandlerRegistration.dispatch(HandlerRegistration.java:98) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.MessageConsumerImpl.deliver(MessageConsumerImpl.java:183) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.MessageConsumerImpl.doReceive(MessageConsumerImpl.java:168) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.HandlerRegistration.lambda$receive$0(HandlerRegistration.java:49) ~[vertx-core-4.5.1.jar:4.5.1]
        at io.vertx.core.eventbus.impl.HandlerRegistration$$Lambda$554/0x000000084050bc40.run(Unknown Source) ~[?:?]
        at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173) ~[netty-common-4.1.103.Final.jar:4.1.103.Final]
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166) ~[netty-common-4.1.103.Final.jar:4.1.103.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) ~[netty-common-4.1.103.Final.jar:4.1.103.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:566) ~[netty-transport-4.1.103.Final.jar:4.1.103.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.103.Final.jar:4.1.103.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.103.Final.jar:4.1.103.Final]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.103.Final.jar:4.1.103.Final]
        at java.lang.Thread.run(Thread.java:829) ~[?:?]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant