Errors With High Volumes Of Logging Data Causing Some Data Not To Be Written / Audit Log File Lock

(Doc ID 2011337.1)

Last updated on NOVEMBER 07, 2017

Applies to:

Oracle API Gateway - Version 11.1.2 and later
Information in this document applies to any platform.

Symptoms

OAG 11.1.2.1.0 in a cluster with 8 Gateway instances. Patch 18330643 is applied.
Virtualized environment with the 8 Gateway instances on 2-3 physical hosts (exact number unknown).

An A10 loadbalancer is in front of the Gateway instances.
That loabalancer was upgraded recently.

In the policy, a Throttling filter limits the number of requests from the load balancer to 30 requests/second.

Problem:
=======
Intermittently, connections from the loadbalancer get dropped.
Subsequently, many requests are coming in concurrently.
This then triggers a Throttling filter in customer's policy which causes the requests to appear to fail.

Example messages for the initial problem:
ERROR 16/Mar/2015:10:53:02.441 [5a3e3700] Problem writing the message payload to the log file: timeout: reading from xxx.xxx.xxx.xxx:4664
ERROR 16/Mar/2015:10:53:02.442 [5a3e3700] MessageListener.preCircuitInvocation(): com.vordel.dwe.TrafficMonitorMessageListener@5d5cd49f:
java.lang.RuntimeException: java.lang.RuntimeException: timeout: reading from xxx.xxx.xxx.xxx:4664
  at com.vordel.log.rolloverfile.TextRollOverLogger.logMessagePayload(TextRollOverLogger.java:101)
  at com.vordel.log.LogManager.logMessagePayload(LogManager.java:164)
  at com.vordel.log.Log.logMessagePayload(Log.java:70)
  at com.vordel.circuit.MessageProcessor.logMessagePayload(MessageProcessor.java:118)
  at com.vordel.circuit.log.LogMessagePayloadProcessor.invoke(LogMessagePayloadProcessor.java:75)
  at com.vordel.circuit.InvocationEngine.invokeFilter(InvocationEngine.java:160)
  at com.vordel.circuit.Message.logPayload(Message.java:373)
  at com.vordel.dwe.TrafficMonitorMessageListener.preCircuitInvocation(TrafficMonitorMessageListener.java:69)
at com.vordel.circuit.InvocationEngine.recordCircuitStart(InvocationEngine.java:89)
  at com.vordel.circuit.InvocationEngine.invokeCircuit(InvocationEngine.java:32)
  at com.vordel.circuit.InvocationEngine.processMessage(InvocationEngine.java:241)
  at com.vordel.circuit.SyntheticCircuitChainProcessor.invoke(SyntheticCircuitChainProcessor.java:36)
  at com.vordel.dwe.http.HTTPPlugin.invokeDispose(HTTPPlugin.java:300)
  at com.vordel.dwe.http.HTTPPlugin.invoke(HTTPPlugin.java:166)
Caused by: java.lang.RuntimeException: timeout: reading from xxx.xxx.xxx.xxx:4664
  at com.vordel.dwe.NativeContentSource.buffer(Native Method)
  at com.vordel.mime.Body.write(Body.java:364)
  at com.vordel.log.LogMessagePayload.getMessageContents(LogMessagePayload.java:39)
  at com.vordel.log.LogMessagePayload.getPayload(LogMessagePayload.java:46)
  at com.vordel.log.DefaultLogPayloadFormatter.formatLog(DefaultLogPayloadFormatter.java:27)
  at com.vordel.log.rolloverfile.TextRollOverLogger.logMessagePayload(TextRollOverLogger.java:94)
  ... 13 more


(ii)
ERROR 16/Mar/2015:10:53:02.561 [71c40700] MessageListener.preCircuitInvocation(): com.vordel.dwe.TrafficMonitorMessageListener@5d5cd49f:
java.lang.RuntimeException: java.lang.RuntimeException: send failed
  at com.vordel.log.rolloverfile.TextRollOverLogger.logMessagePayload(TextRollOverLogger.java:101)
  at com.vordel.log.LogManager.logMessagePayload(LogManager.java:164)
  at com.vordel.log.Log.logMessagePayload(Log.java:70)
  at com.vordel.circuit.MessageProcessor.logMessagePayload(MessageProcessor.java:118)
  at com.vordel.circuit.log.LogMessagePayloadProcessor.invoke(LogMessagePayloadProcessor.java:75)
  at com.vordel.circuit.InvocationEngine.invokeFilter(InvocationEngine.java:160)
  at com.vordel.circuit.Message.logPayload(Message.java:373)
  at com.vordel.dwe.TrafficMonitorMessageListener.preCircuitInvocation(TrafficMonitorMessageListener.java:69)
  at com.vordel.circuit.InvocationEngine.recordCircuitStart(InvocationEngine.java:89)
  at com.vordel.circuit.InvocationEngine.invokeCircuit(InvocationEngine.java:32)
  at com.vordel.circuit.InvocationEngine.processMessage(InvocationEngine.java:241)
  at com.vordel.circuit.SyntheticCircuitChainProcessor.invoke(SyntheticCircuitChainProcessor.java:36)
  at com.vordel.dwe.http.HTTPPlugin.invokeDispose(HTTPPlugin.java:300)
  at com.vordel.dwe.http.HTTPPlugin.invoke(HTTPPlugin.java:166)
Caused by: java.lang.RuntimeException: send failed
  at com.vordel.dwe.NativeContentSource.buffer(Native Method)
  at com.vordel.mime.Body.write(Body.java:364)
  at com.vordel.log.LogMessagePayload.getMessageContents(LogMessagePayload.java:39)
  at com.vordel.log.LogMessagePayload.getPayload(LogMessagePayload.java:46)
  at com.vordel.log.DefaultLogPayloadFormatter.formatLog(DefaultLogPayloadFormatter.java:27)
  at com.vordel.log.rolloverfile.TextRollOverLogger.logMessagePayload(TextRollOverLogger.java:94)
  ... 13 more

Example subsequent messages:
ERROR 16/Mar/2015:10:53:02.543 [71d41700] ThrottlingProcessor.triggered: Event has been triggered for [Throttling]. The number of messages '30' has been reached within the time period '1 seconds' for Key=[/xxx.xxx.xxx.xxx]
ERROR 16/Mar/2015:10:53:02.544 [5b2f2700] ThrottlingProcessor.triggered: Event has been triggered for [Throttling]. The number of messages '30' has been reached within the time period '1 seconds' for Key=[/xxx.xxx.xxx.xxx]
ERROR 16/Mar/2015:10:53:02.544 [b4f4700] ThrottlingProcessor.triggered: Event has been triggered for [Throttling]. The number of messages '30' has been reached within the time period '1 seconds' for Key=[/xxx.xxx.xxx.xxx]


Other related messages:

% grep "non-recoverable error handling transaction: connection closed" Trace_Log.txt
INFO 16/Mar/2015:10:53:02.451 [5a3e3700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.533 [5bbfb700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.547 [a3e3700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.548 [5b1f1700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.564 [1bdb700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.564 [71c40700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.569 [5b5f5700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.577 [8bcb700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.939 [581c1700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.982 [592d2700] non-recoverable error handling transaction: connection closed
INFO 16/Mar/2015:10:53:02.990 [71438700] non-recoverable error handling transaction: connection closed


In the Gateway instance's access log, the IP address and the HTTP status code can be missing, like this:

[oracle@od-ev-u-ol-762 access]$ cat access.log |grep -iEv '200|401' |tail
- - - [16/03/2015:10:38:04 -0600] "POST /guest/store/PostMarketBasketService HTTP/1.1" - 4098
- - - [16/03/2015:10:39:04 -0600] "POST /guest/store/PostMarketBasketService HTTP/1.1" - 4376
- - - [16/03/2015:10:39:04 -0600] "POST /guest/store/PostMarketBasketService HTTP/1.1" - 4376
- - - [16/03/2015:10:44:39 -0600] "POST /guest/store/PostMarketBasketService HTTP/1.1" - 4376
- - - [16/03/2015:10:45:39 -0600] "POST /guest/store/PostMarketBasketService HTTP/1.1" - 2995
- - - [16/03/2015:10:46:39 -0600] "POST /guest/store/PostMarketBasketService HTTP/1.1" - 4376
172.27.18.5 - - [16/03/2015:10:46:39 -0600] "POST /guest/store/ResolveTransactionService HTTP/1.1" 500 432
172.27.18.5 - - [16/03/2015:10:46:39 -0600] "POST /guest/store/GetMemberStoreService HTTP/1.1" 500 432
172.27.18.5 - - [16/03/2015:10:46:39 -0600] "POST /guest/store/ResolveTransactionService HTTP/1.1" 500 432
172.27.18.5 - - [16/03/2015:10:46:39 -0600] "POST /guest/store/GetMemberStoreService HTTP/1.1" 500 432


The problem has been observed on all 8 Gateway instances.

The problem can disappear on its own after a few minutes, or it can last for hours.

Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms