You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by Björn Kautler <Bj...@kautler.net> on 2022/06/03 16:19:57 UTC
Re: ListAppender in parallel tests
Hi Ralph
Sorry, I was distracted by other things.
> Ideally, parallel tests should use their own LoggerContext. But for the
> ClassLoaderContextSelector (the default) this would require that each
> test have its own ClassLoader. In reality it would be better to create a
> ContextSelect for the framework you are using that keys off of
> something unique for each test to have its own ContextSelector.
>
> I know nothing about a Spock testing framework so I can’t really
> advise you there.
I'm pretty familiar with Spock and also its internals.
Can you elaborate a bit more?
You could use generic terms as you see fit, or use something else you
are familiar with to describe it.
Wouldn't having an own logger context for each test iteration be a
performance problem, opposed to something like a parallel-safe log
appender?
It should be no problem to get a unique identifier per test iteration.
Actually as Spock 2.x is a JUnit 5 platform test engine each iteration
has a unique node id already anyway, have to check whether I can
access it or just generate something new.
But what do I do with that identifier then to make it work properly?
Regards
Björn
Am Do., 14. Apr. 2022 um 20:56 Uhr schrieb Ralph Goers
<ra...@dslextreme.com>:
>
> Ideally, parallel tests should use their own LoggerContext. But for the
> ClassLoaderContextSelector (the default) this would require that each
> test have its own ClassLoader. In reality it would be better to create a
> ContextSelect for the framework you are using that keys off of
> something unique for each test to have its own ContextSelector.
>
> I know nothing about a Spock testing framework so I can’t really
> advise you there.
>
> Ralph
>
> > On Apr 13, 2022, at 5:46 PM, Björn Kautler <Bj...@kautler.net> wrote:
> >
> > Hi
> >
> > I'm currently using ListAppender from log4j2-core-test, to test that
> > the logging of the project does what it should do.
> > For that I configured a ListAppender in the log4j2 config file that is
> > used for the tests.
> > In a custom global Spock extension (the test framework I use), I
> > retrieve the appender
> > using ListAppender.getListAppender and call clear() on it before an
> > iteration starts,
> > so I only get the logs written during that test and it also does not
> > overflow the RAM.
> >
> > Now my problem is, that I'd like to enable parallel execution of the
> > tests which is new in Spock 2.x.
> > But the ListAppender naturally does not like that, as it is the same
> > for the whole JVM.
> >
> > I looked into the LoggerContextRule whether I find something useful there,
> > but - please correct me if I'm wrong - as far as I have seen it also
> > is not capable of parallel execution
> > as it uses system properties and static state, so parallel tests would
> > also overwrite each other I guess.
> >
> > Is there something that could be used that better supports parallel execution?
> > Would maybe a ThreadLocalListAppender help that has thread local
> > fields for events, messages, and data?
> > Or something else that is available?
> >
> > Regards
> > Björn
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-user-help@logging.apache.org
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-user-help@logging.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: ListAppender in parallel tests
Posted by Björn Kautler <Bj...@kautler.net>.
Thanks for the quick reply, but did you actually read my last E-Mail?
I already looked at that code and had additional questions / uncertainties.
Regards
Björn
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: ListAppender in parallel tests
Posted by Matt Sicker <bo...@gmail.com>.
See https://github.com/apache/logging-log4j2/blob/master/log4j-core-test/src/main/java/org/apache/logging/log4j/core/test/junit/LoggerContextResolver.java for the JUnit 5 extension code. If you combine this with a ContextSelector plugin that selects the LoggerContext based on an ExtensionContext.Store, then you can parallelize things pretty efficiently.
—
Matt Sicker
> On Jun 5, 2022, at 20:14, Björn Kautler <Bj...@kautler.net> wrote:
>
> Matt Sicker wrote:
>> If you look at our LoggerContextResolver JUnit 5 extension
>> code (more so in master than in release-2.x as the latter is an older
>> version of the former), you'll see how you can essentially use a
>> LoggerContext per test class or test instance (at least that's where
>> it gets stored for this extension).
>
> I had a look and I could probably port that over to a Spock extension
> fairly easily.
> And opposed to the `LoggerContextRule` it also seems not to use static
> state or system properties.
> But from looking at the code I don't see how this is logger context
> then is used by the SUT code.
>
> Matt Sicker wrote:
>> The other side of things would be
>> making a ContextSelector implementation for log4j-core that could
>> select the LoggerContext to use based on the JUnit ExtensionStore.
>
> Is this the part that would make the `LoggerContext` from the
> extension be used by the SUT code?
> How would it access the extension store in that situation?
> How does it work with the JUnit 5 extension currently then, because I
> see no such context selector?
> Or what is the part I'm missing right now?
>
> Matt Sicker wrote:
>> The implementation details are a bit fuzzy, but there's already logic in
>> LoggerContextResolver to check the test instance for @Factory-style
>> methods (similar to @Bean methods in Spring) for dependency injection setup,
>
> Not sure what you mean, the only thing I see is that it searches for
> `LoggerContextSource` annotations on the class and test method.
>
> Volkan Yazıcı wrote:
>> `LoggerContextRule` in the sources might be a good starting point for you.
>> I am actually interested in your feedback, if you happen to use it somehow.
>
> My feedback for this is already in the original post here.
> Let met quote myself:
>> I looked into the LoggerContextRule whether I find something useful there,
>> but - please correct me if I'm wrong - as far as I have seen it also
>> is not capable of parallel execution
>> as it uses system properties and static state, so parallel tests would
>> also overwrite each other I guess.
>
> Volkan Yazıcı wrote:
>> I would refrain from patching `ListAppender` using `ThreadLocal`s. There
>> might be other components which are subject to misbehaviour when accessed concurrently.
>
> You think log4j is not thread-safe?
> Or how should this statement be interpreted?
>
> Volkan Yazıcı wrote:
>> Hence you better give each of your tests a pristine `LoggerContext`.
>
> If I finally understand how, I might do it like that. :-)
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-user-help@logging.apache.org
>
Re: ListAppender in parallel tests
Posted by Björn Kautler <Bj...@kautler.net>.
Matt Sicker wrote:
> If you look at our LoggerContextResolver JUnit 5 extension
> code (more so in master than in release-2.x as the latter is an older
> version of the former), you'll see how you can essentially use a
> LoggerContext per test class or test instance (at least that's where
> it gets stored for this extension).
I had a look and I could probably port that over to a Spock extension
fairly easily.
And opposed to the `LoggerContextRule` it also seems not to use static
state or system properties.
But from looking at the code I don't see how this is logger context
then is used by the SUT code.
Matt Sicker wrote:
> The other side of things would be
> making a ContextSelector implementation for log4j-core that could
> select the LoggerContext to use based on the JUnit ExtensionStore.
Is this the part that would make the `LoggerContext` from the
extension be used by the SUT code?
How would it access the extension store in that situation?
How does it work with the JUnit 5 extension currently then, because I
see no such context selector?
Or what is the part I'm missing right now?
Matt Sicker wrote:
> The implementation details are a bit fuzzy, but there's already logic in
> LoggerContextResolver to check the test instance for @Factory-style
> methods (similar to @Bean methods in Spring) for dependency injection setup,
Not sure what you mean, the only thing I see is that it searches for
`LoggerContextSource` annotations on the class and test method.
Volkan Yazıcı wrote:
> `LoggerContextRule` in the sources might be a good starting point for you.
> I am actually interested in your feedback, if you happen to use it somehow.
My feedback for this is already in the original post here.
Let met quote myself:
> I looked into the LoggerContextRule whether I find something useful there,
> but - please correct me if I'm wrong - as far as I have seen it also
> is not capable of parallel execution
> as it uses system properties and static state, so parallel tests would
> also overwrite each other I guess.
Volkan Yazıcı wrote:
> I would refrain from patching `ListAppender` using `ThreadLocal`s. There
> might be other components which are subject to misbehaviour when accessed concurrently.
You think log4j is not thread-safe?
Or how should this statement be interpreted?
Volkan Yazıcı wrote:
> Hence you better give each of your tests a pristine `LoggerContext`.
If I finally understand how, I might do it like that. :-)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: ListAppender in parallel tests
Posted by Volkan Yazıcı <vo...@yazi.ci>.
As Ralph has indicated, the best approach would be to create a new
`LoggerContext` for each test verifying the logging behavior.
`LoggerContextRule` in the sources might be a good starting point for you.
I am actually interested in your feedback, if you happen to use it somehow.
<speculate>We might consider bundling such goodies into a test helper
module or such. Documenting such practices could also serve well for the
time being too.</speculate>
I would refrain from patching `ListAppender` using `ThreadLocal`s. There
might be other components which are subject to misbehaviour when accessed
concurrently. Hence you better give each of your tests a pristine
`LoggerContext`.
On Fri, Jun 3, 2022 at 6:39 PM Matt Sicker <bo...@gmail.com> wrote:
> I'd imagine that the overhead of a LoggerContext per test would be
> fairly low as long as you're not configuring hundreds of loggers in
> each test. If you look at our LoggerContextResolver JUnit 5 extension
> code (more so in master than in release-2.x as the latter is an older
> version of the former), you'll see how you can essentially use a
> LoggerContext per test class or test instance (at least that's where
> it gets stored for this extension). The other side of things would be
> making a ContextSelector implementation for log4j-core that could
> select the LoggerContext to use based on the JUnit ExtensionStore. The
> implementation details are a bit fuzzy, but there's already logic in
> LoggerContextResolver to check the test instance for @Factory-style
> methods (similar to @Bean methods in Spring) for dependency injection
> setup, so it can't be _too_ complicated to further wire these things
> together. Alternatively, some sort of ThreadLocal-based
> ContextSelector would also work (as long as the LoggerContext is
> stopped or reconfigured on each test; otherwise, once a thread is
> reused, it'll get an existing LoggerContext instead of a fresh one).
> It's also possible that the existing implementation in master is
> already parallel-friendly and I just haven't found a way to verify
> that yet.
>
> A parallel-safe in-memory appender for testing kind of seems like the
> correct route still, though. Looking at the code in ListAppender, I'm
> not really sure why it's global.
>
> On Fri, Jun 3, 2022 at 11:21 AM Björn Kautler <Bj...@kautler.net> wrote:
> >
> > Hi Ralph
> >
> > Sorry, I was distracted by other things.
> >
> > > Ideally, parallel tests should use their own LoggerContext. But for the
> > > ClassLoaderContextSelector (the default) this would require that each
> > > test have its own ClassLoader. In reality it would be better to create
> a
> > > ContextSelect for the framework you are using that keys off of
> > > something unique for each test to have its own ContextSelector.
> > >
> > > I know nothing about a Spock testing framework so I can’t really
> > > advise you there.
> >
> > I'm pretty familiar with Spock and also its internals.
> > Can you elaborate a bit more?
> > You could use generic terms as you see fit, or use something else you
> > are familiar with to describe it.
> >
> > Wouldn't having an own logger context for each test iteration be a
> > performance problem, opposed to something like a parallel-safe log
> > appender?
> >
> > It should be no problem to get a unique identifier per test iteration.
> > Actually as Spock 2.x is a JUnit 5 platform test engine each iteration
> > has a unique node id already anyway, have to check whether I can
> > access it or just generate something new.
> > But what do I do with that identifier then to make it work properly?
> >
> > Regards
> > Björn
> >
> > Am Do., 14. Apr. 2022 um 20:56 Uhr schrieb Ralph Goers
> > <ra...@dslextreme.com>:
> > >
> > > Ideally, parallel tests should use their own LoggerContext. But for the
> > > ClassLoaderContextSelector (the default) this would require that each
> > > test have its own ClassLoader. In reality it would be better to create
> a
> > > ContextSelect for the framework you are using that keys off of
> > > something unique for each test to have its own ContextSelector.
> > >
> > > I know nothing about a Spock testing framework so I can’t really
> > > advise you there.
> > >
> > > Ralph
> > >
> > > > On Apr 13, 2022, at 5:46 PM, Björn Kautler <Bj...@kautler.net>
> wrote:
> > > >
> > > > Hi
> > > >
> > > > I'm currently using ListAppender from log4j2-core-test, to test that
> > > > the logging of the project does what it should do.
> > > > For that I configured a ListAppender in the log4j2 config file that
> is
> > > > used for the tests.
> > > > In a custom global Spock extension (the test framework I use), I
> > > > retrieve the appender
> > > > using ListAppender.getListAppender and call clear() on it before an
> > > > iteration starts,
> > > > so I only get the logs written during that test and it also does not
> > > > overflow the RAM.
> > > >
> > > > Now my problem is, that I'd like to enable parallel execution of the
> > > > tests which is new in Spock 2.x.
> > > > But the ListAppender naturally does not like that, as it is the same
> > > > for the whole JVM.
> > > >
> > > > I looked into the LoggerContextRule whether I find something useful
> there,
> > > > but - please correct me if I'm wrong - as far as I have seen it also
> > > > is not capable of parallel execution
> > > > as it uses system properties and static state, so parallel tests
> would
> > > > also overwrite each other I guess.
> > > >
> > > > Is there something that could be used that better supports parallel
> execution?
> > > > Would maybe a ThreadLocalListAppender help that has thread local
> > > > fields for events, messages, and data?
> > > > Or something else that is available?
> > > >
> > > > Regards
> > > > Björn
> > > >
> > > > ---------------------------------------------------------------------
> > > > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > > > For additional commands, e-mail: log4j-user-help@logging.apache.org
> > > >
> > >
> > >
> > > ---------------------------------------------------------------------
> > > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > > For additional commands, e-mail: log4j-user-help@logging.apache.org
> > >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-user-help@logging.apache.org
> >
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-user-help@logging.apache.org
>
>
Re: ListAppender in parallel tests
Posted by Matt Sicker <bo...@gmail.com>.
I'd imagine that the overhead of a LoggerContext per test would be
fairly low as long as you're not configuring hundreds of loggers in
each test. If you look at our LoggerContextResolver JUnit 5 extension
code (more so in master than in release-2.x as the latter is an older
version of the former), you'll see how you can essentially use a
LoggerContext per test class or test instance (at least that's where
it gets stored for this extension). The other side of things would be
making a ContextSelector implementation for log4j-core that could
select the LoggerContext to use based on the JUnit ExtensionStore. The
implementation details are a bit fuzzy, but there's already logic in
LoggerContextResolver to check the test instance for @Factory-style
methods (similar to @Bean methods in Spring) for dependency injection
setup, so it can't be _too_ complicated to further wire these things
together. Alternatively, some sort of ThreadLocal-based
ContextSelector would also work (as long as the LoggerContext is
stopped or reconfigured on each test; otherwise, once a thread is
reused, it'll get an existing LoggerContext instead of a fresh one).
It's also possible that the existing implementation in master is
already parallel-friendly and I just haven't found a way to verify
that yet.
A parallel-safe in-memory appender for testing kind of seems like the
correct route still, though. Looking at the code in ListAppender, I'm
not really sure why it's global.
On Fri, Jun 3, 2022 at 11:21 AM Björn Kautler <Bj...@kautler.net> wrote:
>
> Hi Ralph
>
> Sorry, I was distracted by other things.
>
> > Ideally, parallel tests should use their own LoggerContext. But for the
> > ClassLoaderContextSelector (the default) this would require that each
> > test have its own ClassLoader. In reality it would be better to create a
> > ContextSelect for the framework you are using that keys off of
> > something unique for each test to have its own ContextSelector.
> >
> > I know nothing about a Spock testing framework so I can’t really
> > advise you there.
>
> I'm pretty familiar with Spock and also its internals.
> Can you elaborate a bit more?
> You could use generic terms as you see fit, or use something else you
> are familiar with to describe it.
>
> Wouldn't having an own logger context for each test iteration be a
> performance problem, opposed to something like a parallel-safe log
> appender?
>
> It should be no problem to get a unique identifier per test iteration.
> Actually as Spock 2.x is a JUnit 5 platform test engine each iteration
> has a unique node id already anyway, have to check whether I can
> access it or just generate something new.
> But what do I do with that identifier then to make it work properly?
>
> Regards
> Björn
>
> Am Do., 14. Apr. 2022 um 20:56 Uhr schrieb Ralph Goers
> <ra...@dslextreme.com>:
> >
> > Ideally, parallel tests should use their own LoggerContext. But for the
> > ClassLoaderContextSelector (the default) this would require that each
> > test have its own ClassLoader. In reality it would be better to create a
> > ContextSelect for the framework you are using that keys off of
> > something unique for each test to have its own ContextSelector.
> >
> > I know nothing about a Spock testing framework so I can’t really
> > advise you there.
> >
> > Ralph
> >
> > > On Apr 13, 2022, at 5:46 PM, Björn Kautler <Bj...@kautler.net> wrote:
> > >
> > > Hi
> > >
> > > I'm currently using ListAppender from log4j2-core-test, to test that
> > > the logging of the project does what it should do.
> > > For that I configured a ListAppender in the log4j2 config file that is
> > > used for the tests.
> > > In a custom global Spock extension (the test framework I use), I
> > > retrieve the appender
> > > using ListAppender.getListAppender and call clear() on it before an
> > > iteration starts,
> > > so I only get the logs written during that test and it also does not
> > > overflow the RAM.
> > >
> > > Now my problem is, that I'd like to enable parallel execution of the
> > > tests which is new in Spock 2.x.
> > > But the ListAppender naturally does not like that, as it is the same
> > > for the whole JVM.
> > >
> > > I looked into the LoggerContextRule whether I find something useful there,
> > > but - please correct me if I'm wrong - as far as I have seen it also
> > > is not capable of parallel execution
> > > as it uses system properties and static state, so parallel tests would
> > > also overwrite each other I guess.
> > >
> > > Is there something that could be used that better supports parallel execution?
> > > Would maybe a ThreadLocalListAppender help that has thread local
> > > fields for events, messages, and data?
> > > Or something else that is available?
> > >
> > > Regards
> > > Björn
> > >
> > > ---------------------------------------------------------------------
> > > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > > For additional commands, e-mail: log4j-user-help@logging.apache.org
> > >
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-user-help@logging.apache.org
> >
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-user-help@logging.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org