SAP Knowledge Base Article - Preview

3123341 - LoggingAPI causes bottleneck during high load of messages in SAP Process Integration

Symptom

In SAP Process Integration/SAP Process Orchestration system, you started to notice severe performance issues in your system related to the message processing.

Messages are increasing in the Scheduled/To Be Delivered status and the backlog in the DispatchDisp queue is also increasing.

If you capture some thread dumps while the issue is happening, you can see that several threads are blocked waiting to lock a resource. Similar to the stack below:

  • java.lang.Thread.State: BLOCKED (on object monitor)
     at com.sap.engine.messaging.impl.core.queue.Queue.checkAndIncreaseWorkers()V(Queue.java:665)
     - waiting to lock <0x00000006a51d8ff0> (a com.sap.engine.messaging.impl.core.queue.provider.WeightedRoundRobinQueueProvider)

If you search for the resource above (0x00000006a51d8ff0), you can see that it is currently locked by a thread which is using the LoggingAPI to write logs into the OS (default traces):

  • "MS Queue Worker [Dispatch]" #3046 prio=5 os_prio=0 cpu=7984480.00 [reset 7984270.00] ms elapsed=12846.70 [reset 12609.73] s allocated=3662732934712 B (3.33 TB) [reset 3662705029776 B (3.33 TB)] defined_classes=31
    io= file i/o: 2237827/265280220635 B, net i/o: 475543309/1885648 B, files opened:3, socks opened:2  [reset file i/o: 2236547/265280220120 B, net i/o: 475538959/1866003 B, files opened:2, socks opened:2 ] 
    user="" isapplicationthread="true" tid=0x00007f0110200800 nid=0xe8e7 / 59623  pthread-id=139639260653312 runnable   [_thread_blocked (_at_safepoint), stack(0x00007f004c672000,0x00007f004c873000)] [0x00007f004c86f000]
       java.lang.Thread.State: RUNNABLE
     at java.io.FileOutputStream.writeBytesWithPath([BIIZLjava/lang/String;)V(Native Method)
     at java.io.FileOutputStream.write([BII)V(FileOutputStream.java:341)
     at sun.nio.cs.StreamEncoder.writeBytes()V(StreamEncoder.java:221)
     at sun.nio.cs.StreamEncoder.implFlushBuffer()V(StreamEncoder.java:291)
     at sun.nio.cs.StreamEncoder.implFlush()V(StreamEncoder.java:295)
     at sun.nio.cs.StreamEncoder.flush()V(StreamEncoder.java:141)
     - locked <0x000000065b44bdd0> (a java.io.OutputStreamWriter)
     at java.io.OutputStreamWriter.flush()V(OutputStreamWriter.java:229)
     at com.sap.tc.logging.StreamLog.flushInt()V(StreamLog.java:192)
     - locked <0x000000069ab844b0> (a com.sap.tc.logging.FileLog)
     at com.sap.tc.logging.Log.flush()V(Log.java:572)
     at com.sap.tc.logging.Log.writeInternalByAPI(Lcom/sap/tc/logging/LogRecord;)Lcom/sap/tc/logging/LogRecord;(Log.java:905)
     at com.sap.tc.logging.LogController.writeToLogs(Ljava/util/Collection;Lcom/sap/tc/logging/LogRecord;)Lcom/sap/tc/logging/LogRecord;(LogController.java:2890)
     at com.sap.tc.logging.LogController.messageInternal(Lcom/sap/tc/logging/LogRecord;)Lcom/sap/tc/logging/LogRecord;(LogController.java:2010)
     at com.sap.tc.logging.LogController.prepareLogRecord(Lcom/sap/tc/logging/LogRecord;Ljava/lang/String;Ljava/lang/String;Ljava/lang/String;)Lcom/sap/tc/logging/LogRecord;(LogController.java:2112)
     at com.sap.tc.logging.LogController.logTInt(ILcom/sap/tc/logging/LogController;[Lcom/sap/tc/logging/LogController;Ljava/lang/String;Ljava/lang/String;I[Ljava/lang/Object;Ljava/lang/Throwable;Ljava/lang/String;Ljava/lang/String;Ljava/lang/String;Ljava/lang/String;)Lcom/sap/tc/logging/LogRecord;(LogController.java:2172)
     at com.sap.tc.logging.LogController.logTInt(ILcom/sap/tc/logging/LogController;[Lcom/sap/tc/logging/LogController;Ljava/lang/String;Ljava/lang/String;I[Ljava/lang/Object;Ljava/lang/Throwable;Ljava/lang/String;Ljava/lang/String;Ljava/lang/String;)Lcom/sap/tc/logging/LogRecord;(LogController.java:2149)
     at com.sap.tc.logging.Location.entering(Ljava/lang/String;[Ljava/lang/Object;)Lcom/sap/tc/logging/LogRecord;(Location.java:8598)
     at com.sap.engine.messaging.impl.util.Trace.entering(Ljava/lang/String;[Ljava/lang/Object;)V(Trace.java:141)
     at com.sap.engine.messaging.impl.core.queue.provider.limitation.ReceiverPerInterfaceLimitation.unlimitedProcessing(Lcom/sap/engine/messaging/impl/core/queue/QueueEntry;)Z(ReceiverPerInterfaceLimitation.java:147)
     at com.sap.engine.messaging.impl.core.queue.provider.limitation.ReceiverPerInterfaceLimitation.hasResources(Lcom/sap/engine/messaging/impl/core/queue/QueueEntry;)Z(ReceiverPerInterfaceLimitation.java:272)
     at com.sap.engine.messaging.impl.core.queue.provider.limitation.CompositeLimitation.hasResources(Lcom/sap/engine/messaging/impl/core/queue/QueueEntry;)Z(CompositeLimitation.java:137)
     at com.sap.engine.messaging.impl.core.queue.provider.LimitedQueueProvider.capacityAvailable(Lcom/sap/engine/messaging/impl/core/queue/QueueEntry;)Z(LimitedQueueProvider.java:196)
     at com.sap.engine.messaging.impl.core.queue.Queue.isSaturated(Lcom/sap/engine/messaging/impl/core/queue/QueueEntry;)Z(Queue.java:1815)
     - locked <0x00000006cb1b7ce8> (a java.lang.Object)
     at com.sap.engine.messaging.impl.core.queue.provider.WeightedRoundRobinQueueProvider.removeNext()Lcom/sap/engine/messaging/impl/core/queue/QueueEntry;(WeightedRoundRobinQueueProvider.java:215)
     - locked <0x00000006c72c4328> (a com.sap.engine.messaging.impl.core.queue.Queue)
     - locked <0x00000006a5343140> (a com.sap.engine.messaging.impl.util.HashQueue)
     at com.sap.engine.messaging.impl.core.queue.Queue.run()V(Queue.java:1007)
     - locked <0x00000006a51d8ff0> (a com.sap.engine.messaging.impl.core.queue.provider.WeightedRoundRobinQueueProvider)
     at com.sap.engine.messaging.runtime.MSWorkWrapper.run()V(MSWorkWrapper.java:58)
     at com.sap.engine.core.thread.impl3.ActionObject.run()Ljava/lang/Object;(ActionObject.java:37)
     at java.security.AccessController.doPrivileged(Ljava/security/PrivilegedAction;Ljava/security/AccessControlContext;)Ljava/lang/Object;(Native Method)
     at com.sap.engine.core.thread.impl3.SingleThread.execute(Lcom/sap/engine/core/thread/ThreadContextImpl;)V(SingleThread.java:185)
     at com.sap.engine.core.thread.impl3.SingleThread.run()V(SingleThread.java:302)
       Locked ownable synchronizers:
     - None


Read more...

Environment

SAP Process Integration

SAP NetWeaver

Product

SAP NetWeaver 7.5

Keywords

Logging, LoggingAPI, Tracing, Log, Performance, Scheduled, ToBeDelivered, To Be Delivered, Waiting, DispatchDisp, Dispatch, Messaging, Queue, Thread, WeightedRoundRobinQueueProvider, SAP, PI, Process Integration, PO, Process Orchestration, XI, 7.5, 7.4, 7.3, 7.31, 7.1 , KBA , BC-XI-CON-MSG , Messaging System , Problem

About this page

This is a preview of a SAP Knowledge Base Article. Click more to access the full version on SAP ONE Support launchpad (Login required).

Search for additional results

Visit SAP Support Portal's SAP Notes and KBA Search.