You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@maven.apache.org by Tibor Digaňa <ti...@googlemail.com.INVALID> on 2021/07/08 13:23:33 UTC
Race condition in slf4j-simple
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
Re: Race condition in slf4j-simple
Posted by Tibor Digana <ti...@apache.org>.
Hi Ceki,
The Jira issue is https://jira.qos.ch/browse/SLF4J-515
T
On Thu, Jul 8, 2021 at 3:54 PM Ceki <ce...@qos.ch> 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
Posted by Tibor Digana <ti...@apache.org>.
Hi Ceki,
The Jira issue is https://jira.qos.ch/browse/SLF4J-515
T
On Thu, Jul 8, 2021 at 3:54 PM Ceki <ce...@qos.ch> 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
Posted by Ceki <ce...@qos.ch>.
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
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
For additional commands, e-mail: users-help@maven.apache.org
Re: Race condition in slf4j-simple
Posted by Ceki <ce...@qos.ch>.
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
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@maven.apache.org
For additional commands, e-mail: dev-help@maven.apache.org