Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Duplicate
-
scr-2.1.16
Description
With R7 logging, it does not seem to be possible to deactivate the SCR activation log-messages if DEBUG mode is activated for a component.
E.g. if you want to debug a component named "org.test.Main" you would set the log-level for this component to "DEBUG" in the logger config.
As SCR also uses the logger "org.test.Main" for logging its activation messages (on DEBUG level) it also starts to verbosely log this information.
This makes it hard to see the DEBUG messages of the component itself:
DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : BundleComponentActivator : ComponentHolder created. DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Dependency Manager created admininterface=org.osgi.service.cm.ConfigurationAdmin, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=admin, field-option=replace, collection-type=null, parameter=null DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Dependency Manager created loggerFactoryinterface=org.osgi.service.log.LogService, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=loggerFactory, field-option=replace, collection-type=null, parameter=null DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Component created: DS=DS13, implementation=org.test.Main, immediate=true, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[org.test.Main] DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Component Services: scope=singleton, services=[org.test.Main] DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Component Properties: {} DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Querying state disabled DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Querying state disabled DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Component can not be activated since it is in state disabled DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main] : Querying state disabled DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Updating target filters DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : No change in target property for dependency admin: currently registered: false DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : No existing service listener to unregister for dependency admin DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Setting target property for dependency admin to null DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : New service tracker for admin, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.cm.ConfigurationAdmin), eventFilter null, initialReferenceFilter (objectClass=org.osgi.service.cm.ConfigurationAdmin) DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm admin tracker reset (closed) DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm admin tracker opened DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : registering service listener for dependency admin DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : No change in target property for dependency loggerFactory: currently registered: false DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : No existing service listener to unregister for dependency loggerFactory DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Setting target property for dependency loggerFactory to null DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : New service tracker for loggerFactory, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.log.LogService), eventFilter null, initialReferenceFilter (objectClass=org.osgi.service.log.LogService) DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm loggerFactory tracker reset (closed) DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm loggerFactory tracking 1 SingleStatic added [org.osgi.service.log.LogService, org.osgi.service.log.LoggerFactory] (enter) DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm loggerFactory tracking 1 SingleStatic active: false trackerOpened: false optional: false DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm loggerFactory tracking 1 SingleStatic added [org.osgi.service.log.LogService, org.osgi.service.log.LoggerFactory] (exit) DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm loggerFactory tracker opened DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : registering service listener for dependency loggerFactory DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Changed state from disabled to unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Component enabled DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : ActivateInternal DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Activating component from state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Dependency not satisfied: admin 16:37:08.970 DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Not all dependencies satisfied, cannot activate DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm admin tracking 2 SingleStatic added [org.osgi.service.cm.ConfigurationAdmin] (enter) DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : ActivateInternal DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Activating component from state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state unsatisfiedReference DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Changed state from unsatisfiedReference to satisfied DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : registration change queue [registered] DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Checking constructor public org.test.Main() DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Found constructor with 0 arguments : public org.test.Main() DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : getting field: admin DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Locating field admin in class org.test.Main DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : getReferenceClass: Looking for interface class org.osgi.service.cm.ConfigurationAdmin through loader of org.test.Main DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : getParameterClass: Found class org.osgi.service.cm.ConfigurationAdmin DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Found field: org.osgi.service.cm.ConfigurationAdmin org.test.Main.admin DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : getting field: loggerFactory DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Locating field loggerFactory in class org.test.Main DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : getReferenceClass: Looking for interface class org.osgi.service.log.LogService through loader of org.test.Main DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : getParameterClass: Found class org.osgi.service.log.LogService DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Found field: org.osgi.service.log.LogService org.test.Main.loggerFactory DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : This thread collected dependencies DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : getService (single component manager) dependencies collected. DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state satisfied DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Querying state satisfied DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : For dependency admin, optional: false; to bind: [[RefPair: ref: [[org.osgi.service.cm.ConfigurationAdmin]] service: [org.apache.felix.cm.impl.ConfigurationAdminImpl@3349e9bb]]] DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : For dependency loggerFactory, optional: false; to bind: [[RefPair: ref: [[org.osgi.service.log.LogService, org.osgi.service.log.LoggerFactory]] service: [org.apache.felix.log.LogServiceImpl@409bf450]]] DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : getting activate: activate DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Locating method activate in class org.test.Main DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Declared Method org.test.Main.activate([interface org.osgi.service.component.ComponentContext]) not found DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Found activate method: public void org.test.Main.activate() DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : invoking activate: activate: parameters [] DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : invoked activate: activate DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Set implementation object for component DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : Changed state from satisfied to active DEBUG org.test.Main - bundle org.test:0.0.0 (4)[org.test.Main(0)] : dm admin tracking 2 SingleStatic added [org.osgi.service.cm.ConfigurationAdmin] (exit)
This behavior was introduced with FELIX-5866. In the comments of the issue it is stated that the log level of SCR can now be configured by LoggerAdmin. But this is not the case (or I am missing something) because the Logger configuration used is the one of the component (here "org.test.Main") and not the one of SCR.
With R6 logging it was possible to disable this as the SCR configuration was also checked.
With R7 it is not (as R7LogServiceLogger.checkScrConfig() returns false).
There is also no possibility to filter these messages out as they are logged on the component logger and not on an SCR logger.
Maybe as a solution the SCR log-level should be checked too, i.e. loggerFactory.getLogger("org.apache.felix.scr").isLogEnabled(...).