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/04/13 15:46:02 UTC
ListAppender in parallel tests
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
Re: ListAppender in parallel tests
Posted by Björn Kautler <Bj...@kautler.net>.
> I came to the conclusion that there is no satisfactory solution to what I
intend to do.
Lies, lies, lies.
Everything alternative facts. :-D
Ralph had a simple but brilliant idea that he mentioned in LOG4J2-1094.
I removed all the custom logic and instead now enable
`log4j.isThreadContextMapInheritable`,
and then use a TCM entry to identify the log messages properly and
associate them to the correct test iteration.
This even works properly with the static logger fields.
With this I can properly identify the log messages done within a test
iteration, also on child threads,
and after the test I can use the same key to clear out those log messages
from the `ListAppender` to not overflow the RAM.
> I have intentions to share this tooling in `log4j-core-test`, let me know
if you are interested.
Thanks, but it looks like I'm perfectly fine with the TCM solution which
also is much leaner. :-)
Regards
Björn
Am Mo., 8. Mai 2023 um 13:35 Uhr schrieb Volkan Yazıcı <vo...@yazi.ci>:
> Thanks so much for the elaborate investigation and taking the effort to
> share your findings with us. I want to participate in this therapy session.
>
> I learnt the hard way that one should test the logging behaviour of a
> certain class. That is, the logging behaviour of subject should be a part
> of business requirements and the target needs to be the implemented code,
> not the framework/library being used. One should try to verify neither the
> (say) Spring logging, nor custom diagnostic logs. It should be logs
> mandated by business requirements of code you wrote.
>
> I test such classes with a custom JUnit 5 extension I built at work. In a
> nutshell, I create a new stripped `LoggerContext` with a custom `LogEvent`
> recording root appender and store/access it via `ExtensionContext` of
> JUnit. Similar to you, I pass the `Logger` (created using this test-scoped
> `LoggerContext`) to the class using a package-private ctor. This is how it
> looks like while flying:
>
> @Log4jEventRecorderEnabled
> class LoggingDecodingExceptionHandlerTest {
>
> @Test
> void exceptions_should_get_logged(Log4jEventRecorder
> log4jEventRecorder) {
>
> // Execute the logic
> Logger logger =
> log4jEventRecorder.loggerContext().getLogger(Foo.class);
> new Foo(logger).runBusinessLogic(...);
>
> // Verify the logging
> List<LogEvent> events = log4jEventRecorder.events();
> // ...
>
> }
>
> }
>
> Fully thread-safe thanks to `ExtensionContext`-based storage. I have
> intentions to share this tooling in `log4j-core-test`, let me know if you
> are interested.
>
> What if we are not able to pass the `Logger` instance? Judging from my
> experience, a majority of such test cases are invalid. Yet, valid ones do
> exist, at relatively few numbers. For those, I rename the test class to
> `*ForkedTest` and configure Maven to run them in their forked JVM
> instances.
>
> On Fri, May 5, 2023 at 3:23 PM Björn Kautler <Bj...@kautler.net> wrote:
>
> > Hi
> >
> > Thanks for all the hints so far.
> >
> > I had some time to revisit this topic recently.
> > After much blood, sweat and tears (trying out many things, poking around,
> > rethinking things, ...),
> > I came to the conclusion that there is no satisfactory solution to what I
> > intend to do.
> >
> > I'll describe in more detail now what the situation is, what I found out,
> > and with what I ended up doing finally,
> > for others to maybe benefit and for curious people to know.
> > Maybe you even come up with some other option I didn't consider yet.
> > If you are not in either of those groups of people, feel free to stop
> > reading here, so I don't waste your time. :-)
> >
> > ---
> >
> > There are two "categories" of log messages I was interested in in my
> tests.
> > 1. log messages produced by my code
> > 2. log messages produced by Weld
> >
> > The loggers in my code are all instance fields.
> > Even better, they are all injected by CDI, so I can easily control where
> > they are coming from.
> >
> > The loggers in Weld on the other hand are all in static fields in
> > interfaces as I learned now.
> >
> > For my own log messages, I validate that in the right situations, the
> right
> > log messages are written (or not written).
> > For the Weld log messages, I mainly tried to verify that there are no
> WARN
> > or higher messages logged.
> >
> > It turned out that a "thread-local list appender" would not really help.
> > In the unit tests most - but not all - log messages are happening on the
> > test thread, so for the most messages this could have worked,
> > but of course not so much for verifying there are no WARN+ messages
> logged
> > as this could easily miss messages on other threads,
> > and of course not for validating the messages happening on other threads.
> > This is especially bad in the integ tests, where many threads are
> involved
> > that should have been checked for no WARN+ messages.
> >
> > The idea with the thread-id based routing logger sounded interesting.
> > Getting hold of the actual appender for the thread was a bit cumbersome,
> > but nothing that cannot be hidden in a utility method.
> > This - together with capturing the thread id where the other-thread log
> > messages happened - even allowed to test some of those.
> > But other than that it has the same problems the "thread-local list
> > appender" would have had.
> >
> > For verifying there are no WARN+ messages logged, especially in the integ
> > tests,
> > I also tried to configure a custom appender with level WARN that just
> > throws an exception if any log message is produced.
> > (Just now found the `AlwaysFailAppender` that does exactly the same)
> > Unfortunately this also did not work out too well, because the loggers in
> > Weld are not only in static interface fields,
> > they are also done through the JBoss logging library, that captures and
> > ignores any `Throwable` coming out of the underlying log4j2
> > `logger.logMessage(...)` call,
> > so the `ignoreExceptions = false` super constructor argument was
> > effectively useless for verifying the Weld messages, but worked fine for
> > own log messages not done through JBoss logging.
> >
> > So for the Weld loggers that cannot be verified by a failing appender,
> > cannot be verified by thread-based appender, and are kept in static
> fields,
> > I did not have any other idea how to do it, besides maybe somehow
> ensuring
> > each test iteration runs with the classes in dedicated class loaders.
> > While I'm not sure whether this would even be possible in a sane way, I
> > imagine this to be a major performance and memory hog.
> > So in that case it might then probably be easier, cleaner, and better to
> > not run the tests in parallel, but sequentially and keep the old "clear
> > appender before test starts" logic, or reconfigure the logger context.
> > But for now, unless I or you have a better idea how to test it, I decided
> > to just remove these verifications and trust in the users reporting
> > warnings or errors happening due to my library. :-(
> >
> > That leaves me with verifying my own log messages.
> >
> > As described above, even there a thread-based solution is sub-optimal and
> > maybe cannot handle all cases.
> > So I indeed had a look at `LoggerContextRule` and `LoggerContextResolver`
> > so see what they do and possibly port it over to a Spock extension.
> > Actually, both of these do not even create new logger contexts.
> > They get (through calling `Configurator.initialize(...)`) the context
> from
> > the context selector, so e.g. the one for the test classes class loader
> > with the class loader selector or the default context with the basic
> > seletor,
> > and then they reconfigure that context for the given config URL, so they
> > are also both not the least ready for parallel test execution either.
> >
> > And also the `LoggerContextRule` has the option to manually give a
> > `contextSelectorClass`, but it then uses a system property to set it,
> > which a parallel test could then again set to a different value, or use
> > while it shouldn't use that.
> > It also sets two other system properties, that as far as I have seen are
> > used nowhere though, they are just set in the beginning and unset in the
> > end.
> > I guess this is for requesting them manually while debugging test
> execution
> > or similar.
> >
> > So here is what I ended up doing now:
> > - do `Configurator.shutdown(Configurator.initialize("log4j initializer",
> > "log4j2-test.xml"));` before any test starts to bootstrap log4j as I got
> > errors about mbean registration and after disabling mbean usage warnings
> > about multiple enum type converters for the same type as the log4j
> > initialization is not done in a thread-safe way (
> > https://issues.apache.org/jira/browse/LOG4J2-1094)
> > - set `Log4jContextSelector` to
> > `org.apache.logging.log4j.core.selector.BasicContextSelector` so that I
> can
> > inject a newly created logger context using
> `ContextAnchor.THREAD_CONTEXT`
> > that is then used when calling `Configurator.initialize(...)`
> > - have a Spock extensions that creates a new logger context using `new
> > LoggerContext(...)`
> > - set the created context to `ContextAnchor.THREAD_CONTEXT` for the
> > selector to find it
> > - call `Configurator.initialize(...)` which then gets the newly created
> > logger context through the basic selector, configures it and returns it
> > - set the context to `ContextAnchor.THREAD_CONTEXT` again as the context
> > factory did set and unset it
> > - inject the logger context to the test instance
> > - do the test
> > - call `Configurator.shutdown(...)` afterwards
> > - unset the `ContextAnchor.THREAD_CONTEXT`
> >
> > In the test code I then have a CDI producer that uses this logger context
> > to create loggers according to injection points and so gives the right
> > loggers to the SUT,
> > and for the verification, I can get the list appender from that same
> logger
> > context to verify exactly the intended messages.
> >
> > If I would not have injected the loggers, I think by using the basic
> > context selector and setting the `THREAD_CONTEXT` again after the
> > `initialize` call,
> > the code in question would still get the loggers from the right context
> as
> > long as no static logger fields are used.
> >
> > Regards
> > Björn
> >
> >
> > Am Di., 7. Juni 2022 um 20:26 Uhr schrieb Matt Sicker <boards@gmail.com
> >:
> >
> > > Using the LoggerContextResolver extension, you can indeed get a
> > > per-test LoggerContext, but without a corresponding ContextSelector
> > > plugin to go with it, you'll have to use JUnit's parameter resolvers
> > > to get the Logger or LoggerContext rather than using LogManager. While
> > > that pattern works fine in our tests, that's mainly because of what
> > > Piotr mentioned about how we log through StatusLogger in the library,
> > > so that makes testing regular Loggers simpler here.
> > >
> > > On Mon, Jun 6, 2022 at 12:47 AM Piotr P. Karwasz
> > > <pi...@gmail.com> wrote:
> > > >
> > > > Hi, Björn,
> > > >
> > > > On Wed, 13 Apr 2022 at 17:46, Björn Kautler <Bj...@kautler.net>
> > wrote:
> > > > >
> > > > > 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.
> > > >
> > > > The main question that has not been asked in this thread is: are your
> > > > loggers static or instance fields in the classes that you are
> testing?
> > > >
> > > > If it is the former (the far most common scenario), the idea of a
> > > > LoggerContext per test will not work, since the logger is bound to a
> > > > LoggerContext during class initialization. You can however create
> > > > multiple list appenders and use RoutingAppender to select the correct
> > > > one during testing:
> > > >
> > > > <Routing name="Routing">
> > > > <Routes pattern="$${event:ThreadId}">
> > > > <Route>
> > > > <List name="${event:ThreadId}"/>
> > > > </Route>
> > > > </Routes>
> > > > </Routing>
> > > >
> > > > This configuration will get you a different list appender for each
> > > > thread, so your logic should work.
> > > >
> > > > Regarding the Log4j2 unity tests, the situation is different: the
> > > > classes we test do not contain loggers, just a `StatusLogger`. While
> > > > Matt's extension that provides a different logger context per test
> > > > mostly solves the test concurrency problem, the tests that check the
> > > > `StatusLogger` output still can not be run concurrently.
> > > >
> > > > Piotr
> > > >
> > > > ---------------------------------------------------------------------
> > > > 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 Volkan Yazıcı <vo...@yazi.ci>.
Thanks so much for the elaborate investigation and taking the effort to
share your findings with us. I want to participate in this therapy session.
I learnt the hard way that one should test the logging behaviour of a
certain class. That is, the logging behaviour of subject should be a part
of business requirements and the target needs to be the implemented code,
not the framework/library being used. One should try to verify neither the
(say) Spring logging, nor custom diagnostic logs. It should be logs
mandated by business requirements of code you wrote.
I test such classes with a custom JUnit 5 extension I built at work. In a
nutshell, I create a new stripped `LoggerContext` with a custom `LogEvent`
recording root appender and store/access it via `ExtensionContext` of
JUnit. Similar to you, I pass the `Logger` (created using this test-scoped
`LoggerContext`) to the class using a package-private ctor. This is how it
looks like while flying:
@Log4jEventRecorderEnabled
class LoggingDecodingExceptionHandlerTest {
@Test
void exceptions_should_get_logged(Log4jEventRecorder
log4jEventRecorder) {
// Execute the logic
Logger logger =
log4jEventRecorder.loggerContext().getLogger(Foo.class);
new Foo(logger).runBusinessLogic(...);
// Verify the logging
List<LogEvent> events = log4jEventRecorder.events();
// ...
}
}
Fully thread-safe thanks to `ExtensionContext`-based storage. I have
intentions to share this tooling in `log4j-core-test`, let me know if you
are interested.
What if we are not able to pass the `Logger` instance? Judging from my
experience, a majority of such test cases are invalid. Yet, valid ones do
exist, at relatively few numbers. For those, I rename the test class to
`*ForkedTest` and configure Maven to run them in their forked JVM instances.
On Fri, May 5, 2023 at 3:23 PM Björn Kautler <Bj...@kautler.net> wrote:
> Hi
>
> Thanks for all the hints so far.
>
> I had some time to revisit this topic recently.
> After much blood, sweat and tears (trying out many things, poking around,
> rethinking things, ...),
> I came to the conclusion that there is no satisfactory solution to what I
> intend to do.
>
> I'll describe in more detail now what the situation is, what I found out,
> and with what I ended up doing finally,
> for others to maybe benefit and for curious people to know.
> Maybe you even come up with some other option I didn't consider yet.
> If you are not in either of those groups of people, feel free to stop
> reading here, so I don't waste your time. :-)
>
> ---
>
> There are two "categories" of log messages I was interested in in my tests.
> 1. log messages produced by my code
> 2. log messages produced by Weld
>
> The loggers in my code are all instance fields.
> Even better, they are all injected by CDI, so I can easily control where
> they are coming from.
>
> The loggers in Weld on the other hand are all in static fields in
> interfaces as I learned now.
>
> For my own log messages, I validate that in the right situations, the right
> log messages are written (or not written).
> For the Weld log messages, I mainly tried to verify that there are no WARN
> or higher messages logged.
>
> It turned out that a "thread-local list appender" would not really help.
> In the unit tests most - but not all - log messages are happening on the
> test thread, so for the most messages this could have worked,
> but of course not so much for verifying there are no WARN+ messages logged
> as this could easily miss messages on other threads,
> and of course not for validating the messages happening on other threads.
> This is especially bad in the integ tests, where many threads are involved
> that should have been checked for no WARN+ messages.
>
> The idea with the thread-id based routing logger sounded interesting.
> Getting hold of the actual appender for the thread was a bit cumbersome,
> but nothing that cannot be hidden in a utility method.
> This - together with capturing the thread id where the other-thread log
> messages happened - even allowed to test some of those.
> But other than that it has the same problems the "thread-local list
> appender" would have had.
>
> For verifying there are no WARN+ messages logged, especially in the integ
> tests,
> I also tried to configure a custom appender with level WARN that just
> throws an exception if any log message is produced.
> (Just now found the `AlwaysFailAppender` that does exactly the same)
> Unfortunately this also did not work out too well, because the loggers in
> Weld are not only in static interface fields,
> they are also done through the JBoss logging library, that captures and
> ignores any `Throwable` coming out of the underlying log4j2
> `logger.logMessage(...)` call,
> so the `ignoreExceptions = false` super constructor argument was
> effectively useless for verifying the Weld messages, but worked fine for
> own log messages not done through JBoss logging.
>
> So for the Weld loggers that cannot be verified by a failing appender,
> cannot be verified by thread-based appender, and are kept in static fields,
> I did not have any other idea how to do it, besides maybe somehow ensuring
> each test iteration runs with the classes in dedicated class loaders.
> While I'm not sure whether this would even be possible in a sane way, I
> imagine this to be a major performance and memory hog.
> So in that case it might then probably be easier, cleaner, and better to
> not run the tests in parallel, but sequentially and keep the old "clear
> appender before test starts" logic, or reconfigure the logger context.
> But for now, unless I or you have a better idea how to test it, I decided
> to just remove these verifications and trust in the users reporting
> warnings or errors happening due to my library. :-(
>
> That leaves me with verifying my own log messages.
>
> As described above, even there a thread-based solution is sub-optimal and
> maybe cannot handle all cases.
> So I indeed had a look at `LoggerContextRule` and `LoggerContextResolver`
> so see what they do and possibly port it over to a Spock extension.
> Actually, both of these do not even create new logger contexts.
> They get (through calling `Configurator.initialize(...)`) the context from
> the context selector, so e.g. the one for the test classes class loader
> with the class loader selector or the default context with the basic
> seletor,
> and then they reconfigure that context for the given config URL, so they
> are also both not the least ready for parallel test execution either.
>
> And also the `LoggerContextRule` has the option to manually give a
> `contextSelectorClass`, but it then uses a system property to set it,
> which a parallel test could then again set to a different value, or use
> while it shouldn't use that.
> It also sets two other system properties, that as far as I have seen are
> used nowhere though, they are just set in the beginning and unset in the
> end.
> I guess this is for requesting them manually while debugging test execution
> or similar.
>
> So here is what I ended up doing now:
> - do `Configurator.shutdown(Configurator.initialize("log4j initializer",
> "log4j2-test.xml"));` before any test starts to bootstrap log4j as I got
> errors about mbean registration and after disabling mbean usage warnings
> about multiple enum type converters for the same type as the log4j
> initialization is not done in a thread-safe way (
> https://issues.apache.org/jira/browse/LOG4J2-1094)
> - set `Log4jContextSelector` to
> `org.apache.logging.log4j.core.selector.BasicContextSelector` so that I can
> inject a newly created logger context using `ContextAnchor.THREAD_CONTEXT`
> that is then used when calling `Configurator.initialize(...)`
> - have a Spock extensions that creates a new logger context using `new
> LoggerContext(...)`
> - set the created context to `ContextAnchor.THREAD_CONTEXT` for the
> selector to find it
> - call `Configurator.initialize(...)` which then gets the newly created
> logger context through the basic selector, configures it and returns it
> - set the context to `ContextAnchor.THREAD_CONTEXT` again as the context
> factory did set and unset it
> - inject the logger context to the test instance
> - do the test
> - call `Configurator.shutdown(...)` afterwards
> - unset the `ContextAnchor.THREAD_CONTEXT`
>
> In the test code I then have a CDI producer that uses this logger context
> to create loggers according to injection points and so gives the right
> loggers to the SUT,
> and for the verification, I can get the list appender from that same logger
> context to verify exactly the intended messages.
>
> If I would not have injected the loggers, I think by using the basic
> context selector and setting the `THREAD_CONTEXT` again after the
> `initialize` call,
> the code in question would still get the loggers from the right context as
> long as no static logger fields are used.
>
> Regards
> Björn
>
>
> Am Di., 7. Juni 2022 um 20:26 Uhr schrieb Matt Sicker <bo...@gmail.com>:
>
> > Using the LoggerContextResolver extension, you can indeed get a
> > per-test LoggerContext, but without a corresponding ContextSelector
> > plugin to go with it, you'll have to use JUnit's parameter resolvers
> > to get the Logger or LoggerContext rather than using LogManager. While
> > that pattern works fine in our tests, that's mainly because of what
> > Piotr mentioned about how we log through StatusLogger in the library,
> > so that makes testing regular Loggers simpler here.
> >
> > On Mon, Jun 6, 2022 at 12:47 AM Piotr P. Karwasz
> > <pi...@gmail.com> wrote:
> > >
> > > Hi, Björn,
> > >
> > > On Wed, 13 Apr 2022 at 17:46, Björn Kautler <Bj...@kautler.net>
> wrote:
> > > >
> > > > 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.
> > >
> > > The main question that has not been asked in this thread is: are your
> > > loggers static or instance fields in the classes that you are testing?
> > >
> > > If it is the former (the far most common scenario), the idea of a
> > > LoggerContext per test will not work, since the logger is bound to a
> > > LoggerContext during class initialization. You can however create
> > > multiple list appenders and use RoutingAppender to select the correct
> > > one during testing:
> > >
> > > <Routing name="Routing">
> > > <Routes pattern="$${event:ThreadId}">
> > > <Route>
> > > <List name="${event:ThreadId}"/>
> > > </Route>
> > > </Routes>
> > > </Routing>
> > >
> > > This configuration will get you a different list appender for each
> > > thread, so your logic should work.
> > >
> > > Regarding the Log4j2 unity tests, the situation is different: the
> > > classes we test do not contain loggers, just a `StatusLogger`. While
> > > Matt's extension that provides a different logger context per test
> > > mostly solves the test concurrency problem, the tests that check the
> > > `StatusLogger` output still can not be run concurrently.
> > >
> > > Piotr
> > >
> > > ---------------------------------------------------------------------
> > > 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>.
Hi
Thanks for all the hints so far.
I had some time to revisit this topic recently.
After much blood, sweat and tears (trying out many things, poking around,
rethinking things, ...),
I came to the conclusion that there is no satisfactory solution to what I
intend to do.
I'll describe in more detail now what the situation is, what I found out,
and with what I ended up doing finally,
for others to maybe benefit and for curious people to know.
Maybe you even come up with some other option I didn't consider yet.
If you are not in either of those groups of people, feel free to stop
reading here, so I don't waste your time. :-)
---
There are two "categories" of log messages I was interested in in my tests.
1. log messages produced by my code
2. log messages produced by Weld
The loggers in my code are all instance fields.
Even better, they are all injected by CDI, so I can easily control where
they are coming from.
The loggers in Weld on the other hand are all in static fields in
interfaces as I learned now.
For my own log messages, I validate that in the right situations, the right
log messages are written (or not written).
For the Weld log messages, I mainly tried to verify that there are no WARN
or higher messages logged.
It turned out that a "thread-local list appender" would not really help.
In the unit tests most - but not all - log messages are happening on the
test thread, so for the most messages this could have worked,
but of course not so much for verifying there are no WARN+ messages logged
as this could easily miss messages on other threads,
and of course not for validating the messages happening on other threads.
This is especially bad in the integ tests, where many threads are involved
that should have been checked for no WARN+ messages.
The idea with the thread-id based routing logger sounded interesting.
Getting hold of the actual appender for the thread was a bit cumbersome,
but nothing that cannot be hidden in a utility method.
This - together with capturing the thread id where the other-thread log
messages happened - even allowed to test some of those.
But other than that it has the same problems the "thread-local list
appender" would have had.
For verifying there are no WARN+ messages logged, especially in the integ
tests,
I also tried to configure a custom appender with level WARN that just
throws an exception if any log message is produced.
(Just now found the `AlwaysFailAppender` that does exactly the same)
Unfortunately this also did not work out too well, because the loggers in
Weld are not only in static interface fields,
they are also done through the JBoss logging library, that captures and
ignores any `Throwable` coming out of the underlying log4j2
`logger.logMessage(...)` call,
so the `ignoreExceptions = false` super constructor argument was
effectively useless for verifying the Weld messages, but worked fine for
own log messages not done through JBoss logging.
So for the Weld loggers that cannot be verified by a failing appender,
cannot be verified by thread-based appender, and are kept in static fields,
I did not have any other idea how to do it, besides maybe somehow ensuring
each test iteration runs with the classes in dedicated class loaders.
While I'm not sure whether this would even be possible in a sane way, I
imagine this to be a major performance and memory hog.
So in that case it might then probably be easier, cleaner, and better to
not run the tests in parallel, but sequentially and keep the old "clear
appender before test starts" logic, or reconfigure the logger context.
But for now, unless I or you have a better idea how to test it, I decided
to just remove these verifications and trust in the users reporting
warnings or errors happening due to my library. :-(
That leaves me with verifying my own log messages.
As described above, even there a thread-based solution is sub-optimal and
maybe cannot handle all cases.
So I indeed had a look at `LoggerContextRule` and `LoggerContextResolver`
so see what they do and possibly port it over to a Spock extension.
Actually, both of these do not even create new logger contexts.
They get (through calling `Configurator.initialize(...)`) the context from
the context selector, so e.g. the one for the test classes class loader
with the class loader selector or the default context with the basic
seletor,
and then they reconfigure that context for the given config URL, so they
are also both not the least ready for parallel test execution either.
And also the `LoggerContextRule` has the option to manually give a
`contextSelectorClass`, but it then uses a system property to set it,
which a parallel test could then again set to a different value, or use
while it shouldn't use that.
It also sets two other system properties, that as far as I have seen are
used nowhere though, they are just set in the beginning and unset in the
end.
I guess this is for requesting them manually while debugging test execution
or similar.
So here is what I ended up doing now:
- do `Configurator.shutdown(Configurator.initialize("log4j initializer",
"log4j2-test.xml"));` before any test starts to bootstrap log4j as I got
errors about mbean registration and after disabling mbean usage warnings
about multiple enum type converters for the same type as the log4j
initialization is not done in a thread-safe way (
https://issues.apache.org/jira/browse/LOG4J2-1094)
- set `Log4jContextSelector` to
`org.apache.logging.log4j.core.selector.BasicContextSelector` so that I can
inject a newly created logger context using `ContextAnchor.THREAD_CONTEXT`
that is then used when calling `Configurator.initialize(...)`
- have a Spock extensions that creates a new logger context using `new
LoggerContext(...)`
- set the created context to `ContextAnchor.THREAD_CONTEXT` for the
selector to find it
- call `Configurator.initialize(...)` which then gets the newly created
logger context through the basic selector, configures it and returns it
- set the context to `ContextAnchor.THREAD_CONTEXT` again as the context
factory did set and unset it
- inject the logger context to the test instance
- do the test
- call `Configurator.shutdown(...)` afterwards
- unset the `ContextAnchor.THREAD_CONTEXT`
In the test code I then have a CDI producer that uses this logger context
to create loggers according to injection points and so gives the right
loggers to the SUT,
and for the verification, I can get the list appender from that same logger
context to verify exactly the intended messages.
If I would not have injected the loggers, I think by using the basic
context selector and setting the `THREAD_CONTEXT` again after the
`initialize` call,
the code in question would still get the loggers from the right context as
long as no static logger fields are used.
Regards
Björn
Am Di., 7. Juni 2022 um 20:26 Uhr schrieb Matt Sicker <bo...@gmail.com>:
> Using the LoggerContextResolver extension, you can indeed get a
> per-test LoggerContext, but without a corresponding ContextSelector
> plugin to go with it, you'll have to use JUnit's parameter resolvers
> to get the Logger or LoggerContext rather than using LogManager. While
> that pattern works fine in our tests, that's mainly because of what
> Piotr mentioned about how we log through StatusLogger in the library,
> so that makes testing regular Loggers simpler here.
>
> On Mon, Jun 6, 2022 at 12:47 AM Piotr P. Karwasz
> <pi...@gmail.com> wrote:
> >
> > Hi, Björn,
> >
> > On Wed, 13 Apr 2022 at 17:46, Björn Kautler <Bj...@kautler.net> wrote:
> > >
> > > 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.
> >
> > The main question that has not been asked in this thread is: are your
> > loggers static or instance fields in the classes that you are testing?
> >
> > If it is the former (the far most common scenario), the idea of a
> > LoggerContext per test will not work, since the logger is bound to a
> > LoggerContext during class initialization. You can however create
> > multiple list appenders and use RoutingAppender to select the correct
> > one during testing:
> >
> > <Routing name="Routing">
> > <Routes pattern="$${event:ThreadId}">
> > <Route>
> > <List name="${event:ThreadId}"/>
> > </Route>
> > </Routes>
> > </Routing>
> >
> > This configuration will get you a different list appender for each
> > thread, so your logic should work.
> >
> > Regarding the Log4j2 unity tests, the situation is different: the
> > classes we test do not contain loggers, just a `StatusLogger`. While
> > Matt's extension that provides a different logger context per test
> > mostly solves the test concurrency problem, the tests that check the
> > `StatusLogger` output still can not be run concurrently.
> >
> > Piotr
> >
> > ---------------------------------------------------------------------
> > 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>.
Using the LoggerContextResolver extension, you can indeed get a
per-test LoggerContext, but without a corresponding ContextSelector
plugin to go with it, you'll have to use JUnit's parameter resolvers
to get the Logger or LoggerContext rather than using LogManager. While
that pattern works fine in our tests, that's mainly because of what
Piotr mentioned about how we log through StatusLogger in the library,
so that makes testing regular Loggers simpler here.
On Mon, Jun 6, 2022 at 12:47 AM Piotr P. Karwasz
<pi...@gmail.com> wrote:
>
> Hi, Björn,
>
> On Wed, 13 Apr 2022 at 17:46, Björn Kautler <Bj...@kautler.net> wrote:
> >
> > 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.
>
> The main question that has not been asked in this thread is: are your
> loggers static or instance fields in the classes that you are testing?
>
> If it is the former (the far most common scenario), the idea of a
> LoggerContext per test will not work, since the logger is bound to a
> LoggerContext during class initialization. You can however create
> multiple list appenders and use RoutingAppender to select the correct
> one during testing:
>
> <Routing name="Routing">
> <Routes pattern="$${event:ThreadId}">
> <Route>
> <List name="${event:ThreadId}"/>
> </Route>
> </Routes>
> </Routing>
>
> This configuration will get you a different list appender for each
> thread, so your logic should work.
>
> Regarding the Log4j2 unity tests, the situation is different: the
> classes we test do not contain loggers, just a `StatusLogger`. While
> Matt's extension that provides a different logger context per test
> mostly solves the test concurrency problem, the tests that check the
> `StatusLogger` output still can not be run concurrently.
>
> Piotr
>
> ---------------------------------------------------------------------
> 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 "Piotr P. Karwasz" <pi...@gmail.com>.
Hi, Björn,
On Wed, 13 Apr 2022 at 17:46, Björn Kautler <Bj...@kautler.net> wrote:
>
> 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.
The main question that has not been asked in this thread is: are your
loggers static or instance fields in the classes that you are testing?
If it is the former (the far most common scenario), the idea of a
LoggerContext per test will not work, since the logger is bound to a
LoggerContext during class initialization. You can however create
multiple list appenders and use RoutingAppender to select the correct
one during testing:
<Routing name="Routing">
<Routes pattern="$${event:ThreadId}">
<Route>
<List name="${event:ThreadId}"/>
</Route>
</Routes>
</Routing>
This configuration will get you a different list appender for each
thread, so your logic should work.
Regarding the Log4j2 unity tests, the situation is different: the
classes we test do not contain loggers, just a `StatusLogger`. While
Matt's extension that provides a different logger context per test
mostly solves the test concurrency problem, the tests that check the
`StatusLogger` output still can not be run concurrently.
Piotr
---------------------------------------------------------------------
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
Re: ListAppender in parallel tests
Posted by Björn Kautler <Bj...@kautler.net>.
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 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
Re: ListAppender in parallel tests
Posted by Matt Sicker <bo...@gmail.com>.
The main reason why ListAppender doesn't support concurrent tests is
essentially a chicken-or-the-egg scenario. While I'd love to be able
to enable concurrent tests in log4j-core, for example, there are so
many tests that aren't currently configured or written to work
concurrently, nobody got around to implementing concurrency support in
ListAppender to support such a use case. Updates to ListAppender (or
an additional appender supporting concurrency) would certainly be
welcomed as contributions!
On Wed, Apr 13, 2022 at 10:46 AM 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