Freeze: Formatting message with Soap message takes to long time, skipping this formatter

[donatelloOo]

This Soap Message formatter is freezing the whole app, related message can be shown in internal logs.

Formatting message with Soap message takes to long time, skipping this formatter

Disabling it is indeed solving the freeze issue

[svennissel]

Can you append a example Logfile with a working parser?

[benlazaro]

@donatelloOo it would be very helpful to get the steps for reproducing this issue so that we can get it fixed.
Can you provide the app version where this was first encountered?
Can you also provide an example log file (as @svennissel previously requested) so that we can try and reproduce it? We will also use that file to test the fixed code.

[donatelloOo]

I am reproducing it using OLV 1.4.15 with Socket Listener + Log4j2 Json Parser.
Thus, I don't have a file to share, but it can be reproduced every time for a log4j2 producer with following (YAML) configuration:

Configuration:
  status: info
  monitorInterval: 300
  
  properties:
    property:
      name: AsyncLogger.ThreadNameStrategy
      value: UNCACHED

  appenders:
    Socket:
      name: SocketJsonAppender
      host: localhost
      port: 50505
      connectTimeoutMillis: 3000
      JsonLayout:
        eventEol: true
        compact: true
        charset: UTF-8
        endOfLine: "\n"
        properties: true
        locationInfo: true
        includeStacktrace: true
        stacktraceAsString: true

    Root:
      level: info
      AppenderRef:
        ref: SocketJsonAppender

[svennissel]

I created a spring boot application with a socket appender

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Appenders>
        <Console name="console" target="SYSTEM_OUT">
            <PatternLayout>
                <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
            </PatternLayout>
        </Console>
        <Socket name="SocketJsonAppender" host="localhost" port="50505" reconnectionDelayMillis="5000">
            <JsonLayout eventEol="true" compact="true" charset="UTF-8" properties="true" locationInfo="true" includeStacktrace = "true" stacktraceAsString="true" endOfLine="\n">
            </JsonLayout>
        </Socket>
    </Appenders>

    <Loggers>
        <Root level="info">
            <AppenderRef ref="console" />
            <AppenderRef ref="SocketJsonAppender"/>
        </Root>
    </Loggers>
</Configuration>

In the application i log a soap message:

for(int i=0; i<1000; i++) {
      LOGGER.info("<?xml version=\"1.0\"?>\n" +
        "<SoAp:Envelope xmlns:SoAp=\"http://schemas.xmlsoap.org/soap/envelope/\">\n" +
        "  <SoAp:Header>\n" +
        "  </SoAp:Header>\n" +
        "  <SoAp:Body>\n" +
        "    <m:GetStockPrice xmlns:m=\"http://www.example.org/stock\">\n" +
        "      <m:StockName>aaa</m:StockName>\n" +
        "    </m:GetStockPrice>\n" +
        "  </SoAp:Body>\n" +
        "</SoAp:Envelope>");
      Thread.sleep(3_000L);
    }

for me it works fine. I use the version 1.4.18.

Did you have very big soap messages?

What happens if you deactivate soap or all other formatter?

[donatelloOo]

Actually the issue happened on standard messages.
No need to produce a soap message log, a hundred of very simple strings like "[INFO] com.exemple.logger Starting app..." should be enough to reproduce.
Workaround is indeed to disable (all) the formatters, especially soap one, but as they are enabled by default it's a recurrent issue.

[svennissel]

I cannot reproduce it. I have generate 20000 Messages in a second with and without soap. I see no internal log entries. The formatting of messages took 2ms - 160ms. Sorry with no logfiles or samples I cannot help you.

[donatelloOo]

Ok. I will try to setup a reproducer / capture the data.