Migrating data adapters from LS3 to LS4 - from log4j to logback

emese

Hi,

I am in the process of migrating my LS v3 data adapters to LS v4. I've had a look at the Demo adapters (java) shipped with LS v4 and I saw that you have kept log4j for the adapters while Lightstreamer itself uses logback.

I have created an adapters_log_conf.xml in adapters and I have referenced it from adapters.xml via the log_config param.
I have copied log initialization to the init method, using the code that is in ChatDataAdapter.java. I have put the same logger initialization in both my metadata adapter and my dataadapter.

When starting Lightstreamer, sometimes things will go just fine, no problem with logging:

Setting file descriptor limit to 1024
Starting Lightstreamer Server...
Please check logs for detailed information.
20.Jul.11 12:50:42,123 < INFO> This is a trial version.
20.Jul.11 12:50:49,787 < INFO> Lightstreamer Server starting in Vivace edition
20.Jul.11 12:50:50,124 < INFO> Started HTML Adaptor for JMX on port 6666
20.Jul.11 12:50:50,479 < INFO> Started RMI server for JMX on port 8888
20.Jul.11 12:52:00,240 < INFO> Bound RMI Connector for JMX on port 8888 (communication on port 8888)
20.Jul.11 12:52:00,353 < INFO> Bound RMI Connector for Platform mbeans on port 8888 (communication on port 8888)
20.Jul.11 12:52:00,371 < INFO> Started JMXMP Connector for JMX on port 9999
20.Jul.11 12:52:00,384 < INFO> SERVER pool size set by default at 10
20.Jul.11 12:52:00,723 < INFO> Loading Data Adapter FOI.FOI_ADAPTER
20.Jul.11 12:52:00,723 < INFO> Loading Metadata Adapter FOI
20.Jul.11 12:52:01,278 < INFO> Loaded ConnectionPoolManager properties with encoding UTF8
20.Jul.11 12:52:01,485 < INFO> poolman-1: Created pool fids (minpool=0,maxpool=10,maxsize=20,idleTimeout=none)
20.Jul.11 12:52:01,492 < INFO> poolman-1: Created pool foi-auth (minpool=0,maxpool=10,maxsize=30,idleTimeout=180)
20.Jul.11 12:52:01,498 < INFO> FOIDeparturesDataAdapter ready
20.Jul.11 12:52:01,552 < INFO> Finished loading Data Adapter FOI.FOI_ADAPTER
20.Jul.11 12:52:01,552 < INFO> FOIMetaDataAdapter ready
20.Jul.11 12:52:01,970 < INFO> Finished loading Metadata Adapter FOI
20.Jul.11 12:52:02,008 < INFO> Selector pool size set by default at 2
20.Jul.11 12:52:02,267 < INFO> Created selector thread: NIO SSL HANDSHAKE SELECTOR 1
20.Jul.11 12:52:02,271 < INFO> Created selector thread: NIO SSL HANDSHAKE SELECTOR 2
20.Jul.11 12:52:02,329 < INFO> Created selector thread: NIO WRITE SELECTOR 1
20.Jul.11 12:52:02,600 < INFO> Created selector thread: NIO WRITE SELECTOR 2
20.Jul.11 12:52:02,606 < INFO> Created selector thread: NIO READ SELECTOR 1
20.Jul.11 12:52:02,606 < INFO> Created selector thread: NIO READ SELECTOR 2
20.Jul.11 12:52:02,608 < INFO> Created selector thread: NIO CHECK SELECTOR 1
20.Jul.11 12:52:02,609 < INFO> Created selector thread: NIO CHECK SELECTOR 2
20.Jul.11 12:52:02,831 < INFO> Events pool size set by default at 2
20.Jul.11 12:52:02,951 < INFO> Pump pool size set by default at 2
20.Jul.11 12:52:03,500 < INFO> Lightstreamer Server 4.0 build 1513.1.1 starting...
20.Jul.11 12:52:03,859 < INFO> SSL Server "Lightstreamer HTTPS Server" listening to *:8443 ...

but other times log4j will issue error messages:

Setting file descriptor limit to 1024
Starting Lightstreamer Server...
Please check logs for detailed information.
20.Jul.11 13:06:53,103 < INFO> This is a trial version.
20.Jul.11 13:06:54,224 < INFO> Lightstreamer Server starting in Vivace edition
20.Jul.11 13:06:54,329 < INFO> Started HTML Adaptor for JMX on port 6666
20.Jul.11 13:06:54,355 < INFO> Started RMI server for JMX on port 8888
20.Jul.11 13:06:54,519 < INFO> Bound RMI Connector for JMX on port 8888 (communication on port 8888)
20.Jul.11 13:06:54,591 < INFO> Bound RMI Connector for Platform mbeans on port 8888 (communication on port 8888)
20.Jul.11 13:06:54,611 < INFO> Started JMXMP Connector for JMX on port 9999
20.Jul.11 13:06:54,618 < INFO> SERVER pool size set by default at 10
20.Jul.11 13:06:54,692 < INFO> Loading Data Adapter FOI.FOI_ADAPTER
20.Jul.11 13:06:54,692 < INFO> Loading Metadata Adapter FOI
log4j:ERROR Attempted to append to closed appender named [LSFile].
log4j:ERROR Attempted to append to closed appender named [LSConsole].
log4j:ERROR Attempted to append to closed appender named [LSFile].
log4j:ERROR Attempted to append to closed appender named [LSConsole].
log4j:ERROR Attempted to append to closed appender named [LSFile].
log4j:ERROR Attempted to append to closed appender named [LSConsole].
log4j:ERROR Attempted to append to closed appender named [LSFile].
log4j:ERROR Attempted to append to closed appender named [LSConsole].
log4j:ERROR Attempted to append to closed appender named [LSFile].
log4j:ERROR Attempted to append to closed appender named [LSConsole].
20.Jul.11 13:06:54,914 < INFO> Finished loading Metadata Adapter FOI
20.Jul.11 13:06:54,914 < INFO> Finished loading Data Adapter FOI.FOI_ADAPTER
...

Have you seen a similar issue when assembling the demo data adapters? Any idea what might be causing it? I don't change any code between the startup that would work out fine, and the one that doesn't, so I think it is needs to be something related to the order in which things get executed, which is unpredictable at Lightstreamer startup.

After 4 hours I have ended up giving up and migrating the data adapters to use logback. The log4j stuff seems to work so nicely for the Demos, I don't see why it refuses to work for my code :Smile_Ab:

Any comments are welcome :Smile_Ab:

Kind regards,
Emese

Dario Crivelli

In fact, when we moved to Logback for the Server's own log, we decided to keep log4j on the existing example adapters.
This reduced the overall changes and reduced the coupling between the Server and the examples; note that the logging libraries included are visible globally and that the in-process java Adapters are not protected in their own ClassLoader, hence, the logging libraries can be accessed by the Adapters; however, the logging system was not meant to be part of the java Adapter interface.

When the Adapters were able to share the logging system with the Server, there were no initialization issues.
On the other hand, if the Adapters only share the logging system among themselves, we have to ensure that the initialization is performed in the correct sequence, as the Adapters are all initialized in parallel.
By replicating the log4j initialization (as done in init(), in ChatDataAdapter.java) in all Adapters, we have never noticed issues. Actually, our log configuration files are very simple; we just ensured that they would define the same appenders in the same way and that they would all define different loggers.
Is it possible that you define the same appender in different ways on different files?