Re: Race condition in slf4j-simple

[Tibor Digana]

Hi Ceki,

The Jira issue is https://jira.qos.ch/browse/SLF4J-515

T

On Thu, Jul 8, 2021 at 3:54 PM Ceki  wrote:

> Hi Tibor,
>
> Your analysis makes sense. As SimpleLogger acts as an appender as found
> in log4j/logback backends, SimpleLogger should cater for concurrent
> access with some sort of synchronization. It currently does not.
>
> Please create a jira issue for this problem.
>
> Best regards,
> --
> Ceki Gülcü
>
> On 08.07.2021 15:23, Tibor Digaňa wrote:
> > Hi Ceki,
> >
> > We have observed a strange behavior of the logger slf4j-simple when two
> > or more parallel Maven modules log the exceptions and the messages.
> >
> > It produces corrupted lines in the log and they are partially mixed with
> > other lines.
> > The lines look like this and they are obviously not expected in the log.
> >
> > [ERROR] R] *.util.json.formatter.JsonFormatterTest
> >   [ERROR] Process Exit Code: 0
> > [ERROR] *.util.json.formatter.JsonFormatterTest
> >
> >
> > After our analysis we found the place in SLF4J code which seems to be
> > the root cause.
> >
> > The method [1] is a critical section and must be synchronized with a
> > singleton lock which avoids reordering of the nested method calls across
> > multiple Threads. Without it, the normal messages and stack trace may
> > mix especially if two parallel Maven modules print the stacktrace.
> >
> > [1]:
> >
> https://github.com/qos-ch/slf4j/blob/39e3b81e5ea69c6610c8d5fd57fd974e090d9fc1/slf4j-simple/src/main/java/org/slf4j/simple/SimpleLogger.java#L243
> > <
> https://github.com/qos-ch/slf4j/blob/39e3b81e5ea69c6610c8d5fd57fd974e090d9fc1/slf4j-simple/src/main/java/org/slf4j/simple/SimpleLogger.java#L243
> >
> >
> > Pls analyse the class SimpleLogger.java and answer with your opinion
> > about this issue and a proposal with the fix.
> > If there are more other critical sections which need to have some
> > concurrency treatments, we can talk about it in this mailing list.
> >
> > --
> > Cheers
> > Tibor
>
>
>

Re: Race condition in slf4j-simple

[Ceki]

Hi Tibor,

Your analysis makes sense. As SimpleLogger acts as an appender as found 
in log4j/logback backends, SimpleLogger should cater for concurrent 
access with some sort of synchronization. It currently does not.


Please create a jira issue for this problem.

Best regards,
--
Ceki Gülcü

On 08.07.2021 15:23, Tibor Digaňa wrote:

Hi Ceki,

We have observed a strange behavior of the logger slf4j-simple when two 
or more parallel Maven modules log the exceptions and the messages.


It produces corrupted lines in the log and they are partially mixed with 
other lines.

The lines look like this and they are obviously not expected in the log.

[ERROR] R] *.util.json.formatter.JsonFormatterTest
  [ERROR] Process Exit Code: 0
[ERROR] *.util.json.formatter.JsonFormatterTest


After our analysis we found the place in SLF4J code which seems to be 
the root cause.


The method [1] is a critical section and must be synchronized with a 
singleton lock which avoids reordering of the nested method calls across 
multiple Threads. Without it, the normal messages and stack trace may 
mix especially if two parallel Maven modules print the stacktrace.


[1]: 
https://github.com/qos-ch/slf4j/blob/39e3b81e5ea69c6610c8d5fd57fd974e090d9fc1/slf4j-simple/src/main/java/org/slf4j/simple/SimpleLogger.java#L243 



Pls analyse the class SimpleLogger.java and answer with your opinion 
about this issue and a proposal with the fix.
If there are more other critical sections which need to have some 
concurrency treatments, we can talk about it in this mailing list.


--
Cheers
Tibor




-
To unsubscribe, e-mail: users-unsubscr...@maven.apache.org
For additional commands, e-mail: users-h...@maven.apache.org

Race condition in slf4j-simple

[Tibor Digaňa]

Hi Ceki,

We have observed a strange behavior of the logger slf4j-simple when two or
more parallel Maven modules log the exceptions and the messages.

It produces corrupted lines in the log and they are partially mixed with
other lines.
The lines look like this and they are obviously not expected in the log.

[ERROR] R] *.util.json.formatter.JsonFormatterTest
 [ERROR] Process Exit Code: 0
[ERROR] *.util.json.formatter.JsonFormatterTest


After our analysis we found the place in SLF4J code which seems to be the
root cause.

The method [1] is a critical section and must be synchronized with a
singleton lock which avoids reordering of the nested method calls across
multiple Threads. Without it, the normal messages and stack trace may mix
especially if two parallel Maven modules print the stacktrace.

[1]:
https://github.com/qos-ch/slf4j/blob/39e3b81e5ea69c6610c8d5fd57fd974e090d9fc1/slf4j-simple/src/main/java/org/slf4j/simple/SimpleLogger.java#L243

Pls analyse the class SimpleLogger.java and answer with your opinion about
this issue and a proposal with the fix.
If there are more other critical sections which need to have some
concurrency treatments, we can talk about it in this mailing list.

-- 
Cheers
Tibor