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.

Reply via email to