Article - CS391928

Turning on debug, trace or info log for long duration causing performance issues in ThingWorx Platform with warning "http-nio-8080-exec-300" tid=0x493 in WAITING"

Modified: 09-Sep-2025   


Applies To

  • ThingWorx Platform 8.5 to 10.0

Description

  • Turning on debug, trace or info log causes bad overall performance in ThingWorx Platform
  • Change log level to lower levels such as debug, trace, info or all in ApplicationLog or ScriptLog causes the ThingWorx Platform to hang sometimes, and it becomes slow for users to access Composer
  • User cannot access ThingWorx when log level is set to debug or trace or info and running for a while
  • ThingWorx Platform is running and processing slowly
  • How to configure logging or logback.xml in ThingWorx to avoid performance issues 
  • Most of our http-nio threads are in WAITING or BLOCKED status
  • Turning on low log level (E.g: Debug, Trace, Info or All) in a busy production system causes http-nio threads to be waiting on log writing event
  • Example thread dump:
"http-nio-8080-exec-300" tid=0x493 in WAITING 
   - waiting on <0xf558aa2> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 
   - synchronizer <0x2e64c89f> (a java.util.concurrent.ThreadPoolExecutor$Worker) 
   - synchronizer <0xc9b5631> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) 
   - locked <0xc3a7b90> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper) 
   Blocked: 996[-1ms], Waited: 1280736[-1ms] 
   User CPU: 5m25s 
   - synchronizer <0x2e64c89f> (a java.util.concurrent.ThreadPoolExecutor$Worker) 
   - synchronizer <0xc9b5631> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) 
   at sun.misc.Unsafe.park(Native Method) 
   - waiting on <0xf558aa2> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 
   at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) 
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) 
   at java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:353) 
   at ch.qos.logback.core.AsyncAppenderBase.putUninterruptibly(AsyncAppenderBase.java:181) 
   at ch.qos.logback.core.AsyncAppenderBase.put(AsyncAppenderBase.java:172) 
   at ch.qos.logback.core.AsyncAppenderBase.append(AsyncAppenderBase.java:161) 
   at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84) 
   at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) 
   at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270) 
   at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257) 
   at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421) 
   at ch.qos.logback.classic.Logger.filterAndLog_2(Logger.java:414) 
   at ch.qos.logback.classic.Logger.trace(Logger.java:433) 
   at com.thingworx.webservices.context.ThreadLocalContext.getSecurityContext(ThreadLocalContext.java:173) 
   at com.thingworx.system.subsystems.eventprocessing.OrderedEventProcessingSubsystem.report(OrderedEventProcessingSubsystem.java:177) 
   at com.thingworx.things.connected.RemoteThing.setConnected(RemoteThing.java:456) 
   at com.thingworx.things.connected.RemoteThing.bindEndpoint(RemoteThing.java:572) 
   at com.thingworx.communications.platform.modules.DispatchingServerCommunicationModule.fireEndpointRegistryBindingAdded(DispatchingServerCommunicationModule.java:938) 
   at com.thingworx.communications.server.modules.ServerCommunicationModuleBase.addEndpointRegistryBinding(ServerCommunicationModuleBase.java:211) 
   at com.thingworx.communications.platform.modules.DispatchingServerCommunicationModule.doActualBinding(DispatchingServerCommunicationModule.java:578) 
   at com.thingworx.communications.platform.modules.DispatchingServerCommunicationModule.processBindMessage(DispatchingServerCommunicationModule.java:507) 
   at com.thingworx.communications.platform.modules.DispatchingServerCommunicationModule.handleRequest(DispatchingServerCommunicationModule.java:265) 
   at com.thingworx.communications.server.endpoints.DispatchingServerEndpoint.handleRequest(DispatchingServerEndpoint.java:33) 
   at com.thingworx.communications.server.connection.jsr356.AbstractServerConnection.onASDKV1Message(AbstractServerConnection.java:374) 
   at com.thingworx.communications.server.connection.jsr356.AbstractServerConnection.onMessage(AbstractServerConnection.java:340) 
   at sun.reflect.GeneratedMethodAccessor167.invoke(Unknown Source) 
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
   at java.lang.reflect.Method.invoke(Method.java:498) 
   at org.apache.tomcat.websocket.pojo.PojoMessageHandlerWholeBase.onMessage(PojoMessageHandlerWholeBase.java:104) 
   at org.apache.tomcat.websocket.WsFrameBase.sendMessageBinary(WsFrameBase.java:602) 
   at org.apache.tomcat.websocket.server.WsFrameServer.sendMessageBinary(WsFrameServer.java:141) 
   at org.apache.tomcat.websocket.WsFrameBase.processDataBinary(WsFrameBase.java:561) 
   at org.apache.tomcat.websocket.WsFrameBase.processData(WsFrameBase.java:307) 
   at org.apache.tomcat.websocket.WsFrameBase.processInputBuffer(WsFrameBase.java:133) 
   at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:85) 
   at org.apache.tomcat.websocket.server.WsFrameServer.doOnDataAvailable(WsFrameServer.java:183) 
   at org.apache.tomcat.websocket.server.WsFrameServer.notifyDataAvailable(WsFrameServer.java:162) 
   at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.upgradeDispatch(WsHttpUpgradeHandler.java:156) 
   at org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:60) 
   at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:59) 
   at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893) 
   at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1723) 
   at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 
   - locked <0xc3a7b90> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper) 
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) 
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) 
   at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) 
   at java.lang.Thread.run(Thread.java:748) 


"http-nio-8080-exec-301" tid=0x49b in WAITING 
   - waiting on <0xc9b5631> (a java.util.concurrent.locks.ReentrantLock$NonfairSync), held by http-nio-8080-exec-300
   - synchronizer <0x16022ba6> (a java.util.concurrent.ThreadPoolExecutor$Worker) 
   - locked <0x9462225> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper) 
   Blocked: 1101[-1ms], Waited: 1253786[-1ms] 
   User CPU: 5m19s 
   - synchronizer <0x16022ba6> (a java.util.concurrent.ThreadPoolExecutor$Worker) 
   at sun.misc.Unsafe.park(Native Method) 
   - waiting on <0xc9b5631> (a java.util.concurrent.locks.ReentrantLock$NonfairSync), held by http-nio-8080-exec-300 
   at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) 
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836) 
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870) 
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199) 
   at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209) 
   at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285) 
   at com.thingworx.communications.platform.modules.DispatchingServerCommunicationModule.processBindMessage(DispatchingServerCommunicationModule.java:503) 
   at com.thingworx.communications.platform.modules.DispatchingServerCommunicationModule.handleRequest(DispatchingServerCommunicationModule.java:265) 
   at com.thingworx.communications.server.endpoints.DispatchingServerEndpoint.handleRequest(DispatchingServerEndpoint.java:33) 
   at com.thingworx.communications.server.connection.jsr356.AbstractServerConnection.onASDKV1Message(AbstractServerConnection.java:374) 
   at com.thingworx.communications.server.connection.jsr356.AbstractServerConnection.onMessage(AbstractServerConnection.java:340) 
   at sun.reflect.GeneratedMethodAccessor167.invoke(Unknown Source) 
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
   at java.lang.reflect.Method.invoke(Method.java:498) 
   at org.apache.tomcat.websocket.pojo.PojoMessageHandlerWholeBase.onMessage(PojoMessageHandlerWholeBase.java:104) 
   at org.apache.tomcat.websocket.WsFrameBase.sendMessageBinary(WsFrameBase.java:602) 
   at org.apache.tomcat.websocket.server.WsFrameServer.sendMessageBinary(WsFrameServer.java:141) 
   at org.apache.tomcat.websocket.WsFrameBase.processDataBinary(WsFrameBase.java:561) 
   at org.apache.tomcat.websocket.WsFrameBase.processData(WsFrameBase.java:307) 
   at org.apache.tomcat.websocket.WsFrameBase.processInputBuffer(WsFrameBase.java:133) 
   at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:85) 
   at org.apache.tomcat.websocket.server.WsFrameServer.doOnDataAvailable(WsFrameServer.java:183) 
   at org.apache.tomcat.websocket.server.WsFrameServer.notifyDataAvailable(WsFrameServer.java:162) 
   at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.upgradeDispatch(WsHttpUpgradeHandler.java:156) 
   at org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:60) 
   at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:59) 
   at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893) 
   at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1723) 
   at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) 
   - locked <0x9462225> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper) 
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) 
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) 
   at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) 
   at java.lang.Thread.run(Thread.java:748)
This is a printer-friendly version of Article 391928 and may be out of date. For the latest version click CS391928