Hello I created https://ops4j1.jira.com/browse/PAXLOGGING-307 to track this issue.
regards Grzegorz Grzybek pon., 9 gru 2019 o 22:35 Monica Ron <[email protected]> napisał(a): > Thanks. If you do change the code to fix my problem (e.g., swap order of > the generic parameters, or whatever other way you fix it), I hope you can > release a 1.10.x as well as fixing it on the newer 1.11.x, since I can't > use 1.11.x yet. > > I can't even use 1.10.4, as I'm having trouble with a NoSuchMethodError in > some of the pax-logging-log4j2 when printing stack traces. I'll submit a > bug in Jira for that. I didn't try 1.10.3, but 1.10.2 works for printing > stack traces. > > Monica > > On Friday, December 6, 2019 at 12:44:12 AM UTC-5, Grzegorz Grzybek wrote: >> >> Hello >> >> Thank you for this analysis - you are correct. >> The goal of removing map-per-logging facade was to unify logging behavior >> and allowing two bundles to use two different loggers with the same name >> (though now I think the problem was caused by this generification you've >> mentioned). >> >> There's also >> https://github.com/ops4j/org.ops4j.pax.logging/blob/logging-1.11.3/pax-logging-it/src/test/java/org/ops4j/pax/logging/it/Log4J2RestartBothPaxLoggingBundlesIntegrationTest.java >> test that shows what happens when logger was obtained and >> pax-logging-api+pax-logging-log4j2 bundles were restarted. >> >> I added a comment that when logger is obtained when pax-logging-api is >> ACTIVE and then it's stopped, it WON'T be reconnected to a backend. >> Though it seems >> <https://github.com/ops4j/org.ops4j.pax.logging/blob/logging-1.11.3/pax-logging-it/src/test/java/org/ops4j/pax/logging/it/Log4J2RestartBothPaxLoggingBundlesIntegrationTest.java> >> that if logger was obtained when pax-logging-api is stopped (INSTALLED >> state), then it WILL be reconnected to actual backend... >> >> From your description, I believe I can check your problem, but not this >> week. >> >> regards >> Grzegorz Grzybek >> >> pt., 6 gru 2019 o 03:57 Monica Ron <[email protected]> napisał(a): >> >>> I got the tests to run, but I am still working on modifying them to >>> illustrate my problem. It is clear to me from studying the pax logging code >>> and observing its behavior that having the m_loggers maps (whether per >>> logging API or as a single global map) with key=name and value=logger is >>> wrong, and can cause some loggers to get stuck with DefaultServiceLog. >>> However, I don't know yet know how to show it in a unit test. >>> >>> What happens in my Glassfish/Payara setup is: >>> 1. Wars that were already deployed when Payara is restarted start up >>> first (before the pax logging bundles are started up), with pax-logging-api >>> and pax-logging-log4j2 on the classpath, but those pax bundles haven't been >>> activated yet (the Activator class has not run). >>> >>> 2. During #1, the JclLogger and Slf4jLogger get a DefaultServiceLog >>> instance, because they can see the unactivated pax-logging-api code. I >>> don't use either of these directly (our code uses Log4J2), but Mongo uses >>> SLF4J, and Spring uses JCL. During startup of my wars, Mongo uses the same >>> name multiple times when getting loggers, and Spring uses the same name >>> multiple times for getting loggers. This is based on Mongo and Spring >>> behavior (not mine). As I described, when the name is used a second time, >>> the new JclLogger (or Slf4jLogger) replaces the first JclLogger/Slf4jLogger >>> as a value in the m_loggers map. When m_loggers.put(name, jclLogger) is >>> called, the previous JclLogger is returned (standard behavior of the "put" >>> method on a map), and the second (or subsequent, as some come up many >>> times) time "put" is called, the return value of "put" is not null. >>> >>> 3. Payara goes to OSGi start level 2, and activates pax-logging-api by >>> running Activator, and the JclLogger/Slf4jLogger instances that are in the >>> m_loggers maps get updated with a TrackingLogger instead of the original >>> DefaultServiceLog. Then when pax-logging-log4j2 is activated, the >>> JclLogger/Slf4jLogger instances log through the pax logging, based on my >>> settings in org.ops4j.pax.logging.cfg. The JclLogger and Slf4jLogger >>> instances that got removed from the map in #2 still use the >>> DefaultServiceLog, not a TrackingLogger, because the Activator does not >>> know that these instances exist. Mongo logs some status data every few >>> minutes, and some of that still uses the DefaultServiceLog, because the >>> name was used multiple times. The DefaultServiceLog does not respect my >>> configuration that says "don't log this status data [it's at "debug" level, >>> and I set that category to "info" level, but my setting is ignored]. Some >>> Spring code also does not respect my configuration, because some instances >>> of the logger still uses DefaultServiceLog. >>> >>> 4. With Payara now up and running with pax-logging-api and >>> pax-logging-log4j2 fully activated, if I redeploy my war, all instances of >>> JclLogger/Slf4jLogger immediately get TrackingLogger (no >>> DefaultServiceLog), and log based on my org.ops4j.pax.logging.cfg. The >>> Mongo status logging at debug level and the Spring logging that I don't >>> want now goes away. >>> >>> 5. If I restart the domain again, the whole thing starts over--I get >>> stuck with DefaultServiceLog until I redeploy the war while pax-logging-api >>> and pax-logging-log4j2 are fully activated. >>> >>> >>> If I run a profiler (e.g., jvisualvm) on my process, I can see lots of >>> DefaultServiceLog instances still exist after Step #3. After Step #4, many >>> of those DefaultServiceLog instances go away, because the re-deployed war >>> uses only TrackingLogger (because pax-logging-api is already running). If >>> pax-logging was properly replacing all DefaultServiceLog with the >>> TrackingLogger, then Step #3 (as soon as pax-logging-api got activated), >>> then I think *all* of the DefaultServiceLog instances should go away. >>> >>> If m_loggers was stored as key=logger, value=name (as it did before >>> someone added generics in December 2015), then when iterating through the >>> loggers in Activator (would iterate over the keys, not the values), the >>> Activator would still be able to see *all* instances of loggers that ever >>> got created, instead of losing some of them (losing them when name is >>> repeated, if name is the key). >>> >>> =========== >>> I tried running the SimplestPaxLoggingServiceIntegrationTest, but as >>> soon as the test starts, the logger already uses a TrackingLogger (not the >>> DefaultServiceLog). That is, by the time the test starts, the >>> pax-logging-api has already been activated. I need to run a test that >>> creates two or more loggers with the same name *before* pax-logging-api >>> Activator gets called. I can't tell if there are any tests that mimic my >>> situation of getting loggers before the pax-logging-api is activated (so >>> that the DefaultServiceLog is used), and then activating it as part of the >>> test (so that the DefaultServiceLog is replaced with TrackingLogger during >>> the test run). >>> >>> Monica >>> >>> -- >>> -- >>> ------------------ >>> OPS4J - http://www.ops4j.org - [email protected] >>> >>> --- >>> You received this message because you are subscribed to the Google >>> Groups "OPS4J" group. >>> To unsubscribe from this group and stop receiving emails from it, send >>> an email to [email protected]. >>> To view this discussion on the web visit >>> https://groups.google.com/d/msgid/ops4j/80cf1c6a-db69-4463-b85a-5b2b112a27f6%40googlegroups.com >>> <https://groups.google.com/d/msgid/ops4j/80cf1c6a-db69-4463-b85a-5b2b112a27f6%40googlegroups.com?utm_medium=email&utm_source=footer> >>> . >>> >> -- > -- > ------------------ > OPS4J - http://www.ops4j.org - [email protected] > > --- > You received this message because you are subscribed to the Google Groups > "OPS4J" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to [email protected]. > To view this discussion on the web visit > https://groups.google.com/d/msgid/ops4j/132b64d3-6418-47b0-85f7-fd7b9199b8d9%40googlegroups.com > <https://groups.google.com/d/msgid/ops4j/132b64d3-6418-47b0-85f7-fd7b9199b8d9%40googlegroups.com?utm_medium=email&utm_source=footer> > . > -- -- ------------------ OPS4J - http://www.ops4j.org - [email protected] --- You received this message because you are subscribed to the Google Groups "OPS4J" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To view this discussion on the web visit https://groups.google.com/d/msgid/ops4j/CAAdXmhqq24OrCmtBWgEDU6fHFgQ1Ha38naLUPAhANTYT3Z9MyA%40mail.gmail.com.
