How can I log initialization of objects created by Blueprint (Aries) during container initialization in Karaf?

Question

After reading about this, I felt like I understood it and now I am left baffled. Here is what I expect and what I did:

I expect to log into Karaf, reload my bundle, and run log:tail and eventually see a log message like this:

13:28:47.265 INFO [Blueprint] You just created a class called: MyClass.

Technologies used: - OSGI Container implemented by Apache Karaf - Blueprint implemented by Aries

My OSGI bundle imports the pax logger from Karaf

org.slf4j.*; provider=paxlogging

to my understanding, this means that a reference to to the singleton logger of Karaf will be provided at runtime to my application, which only uses an API.

My classes use the SLF4J interface, so the dependency slf4j-api:slf4j-api:1.7.26 exists in my project.
A class exists

Class serves a model

public class MyClass {
  private static final Logger LOGGER = LoggerFactory.getLogger(MyClass.class);
  public MyClass() {
    LOGGER.info("You just created a class called: {}", this);
  }
  @Override
  public String toString() { return "MyClass" };
}

I just followed the specifications for an OSGI LoggerFactory:

Consumers of this API must not implement this type https://osgi.org/specification/osgi.cmpn/7.0.0/service.log.html#org.osgi.service.log.LoggerFactory

Aries creates one:

Blueprint XML

<?xml version="1.0" encoding="UTF-8" ?>
<blueprint xmlns="http://www.osgi.org/xmlns/blueprint/v1.0.0"
           xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
           xsi:schemaLocation="http://www.osgi.org/xmlns/blueprint/v1.0.0 http://www.osgi.org/xmlns/blueprint/v1.0.0/blueprint.xsd">

<description>
    A sample Blueprint XML to demonstrate 
    the initialization procedure in the hopes of reproducing a problem.
</description>

<bean id="myclass1" class=com.stack.MyClass/>
</blueprint>

@Schneider I liked your comment here https://stackoverflow.com/q/28882345/1236128. I think you might have misread my question. I have all that setup (except I use the Gradle biz.aQute.bnd plugin). Objects created early are not logged. I need to know how to solve that. My guess is that I need to query a service manager and get a reference to pax logging early on (not sure how to do that yet). – Jonathan Komar Jul 16 '19 at 12:15
Ah .. it is about not missing log entries. You can inject the org.osgi.service.log.LogService into the blueprint context. Pax logging provides this service and it would make sure you code is only executed when pax logging is ready. – Christian Schneider Jul 16 '19 at 12:30
Appeciated, but the documentation states the LogService is deprecated in favor of the LoggerFactory or Loggers. https://osgi.org/specification/osgi.cmpn/7.0.0/service.log.html – Jonathan Komar Jul 16 '19 at 13:16
You would only use the LogService as kind of a marker service to let your blueprint context wait for it to be ready. You would not use the LogService to log stuff. Pax logging is also implementing a few other interfaces but I gave you the logservice one as it has a spec behind it .. so you do not need to depend on a pax logging specific interface. – Christian Schneider Jul 16 '19 at 13:18
I seem to have run into the same problem again, albeit with an updated version of Karaf and friends. Is it correct in Gradle to have the dependency `compile "org.slf4j:slf4j-api:${slf4jApiVersion}"` or do I need an implementation somewhere? Logging is working for threads that get created later, but not the stuff created early on in the bootstrap phase of Aries Blueprint. Bundle imports `org.slf4j;version="[1.7,2)"` – Jonathan Komar Nov 25 '19 at 08:17
1

The API should be good enough in the dependencies. If logging works for some threads then your dependencies are correct. If you do no see all logs then this might be a bug in pax logging. – Christian Schneider Nov 25 '19 at 12:36

Jonathan Komar · Accepted Answer · 2019-07-23T11:29:41.453

Got this figured out:

The SLF4J API compiled in the bundle is part of the story. The rest is provided in Karaf / Felix by org.ops4j.pax.logging.pax-logging-api. This thing does stuff in the background:

Setups up its own singleton logger factories.
Immediately enables SLF4J API support and logs a message.
One of the singleton logger factories is what SLF4J API needs to create loggers, the Slf4jLoggerFactory. It, which holds a static reference to the PaxLoggingManager object (Slf4jLoggerFactory.setPaxLoggingManager(manager), where manager is new OSGIPaxLoggingManager(bundleContext)). The method getLogger within this singleton returns a new Slf4jLogger(name, paxLogger) object (where name is usually a class name and the paxLogger is either from a FallbackLogFactory.createFallbackLog(FrameworkUtil.getBundle(Logger.class), name) or m_paxLogging.getLogger(name, Slf4jLogger.SLF4J_FQCN). Slf4jLogger

So, it is necessary to bind to this specific Slf4jLoggerFactory (implements ILoggerFactory) so that all of the classes in the bundle get the correct reference when they call getLogger(class). The problem with Aries Blueprint, it seems, is that it lazily binds the SLF4J API to the implementation provided by headers org.ops4j.pax.logging.pax-logging-api. So, I followed Christian Schneider's advice and created a top-level reference in Blueprint that forced Blueprint to wait for the Pax Manager to be ready:

 <reference id="logService" interface="org.osgi.service.log.LogService" availability="mandatory" activation="eager"/>

Then the other top-level managers can depend on this by using depends-on:

<bean id="MyRegistry" class="com.foo.MyRegistry" scope="singleton" factory-method="getSingletonInstance" depends-on="logService">

Of course, I needed to add the following to my OSGI MANIFEST.MF

Import-Package:
org.slf4j;version="[1.7.0,2.0.0)",
org.osgi.service.log,

How can I log initialization of objects created by Blueprint (Aries) during container initialization in Karaf?

Related

2 Answers2