Tobias Gunkel created FELIX-6108:
------------------------------------
Summary: SCR activation log-messages cannot be disabled with R7
LogService
Key: FELIX-6108
URL: https://issues.apache.org/jira/browse/FELIX-6108
Project: Felix
Issue Type: Bug
Components: Declarative Services (SCR)
Affects Versions: scr-2.1.16
Reporter: Tobias Gunkel
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 the activation messages and also starts
to verbosely log this information which makes it hard to see the DEBUG messages
of the component itself:
{code:java}
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)
{code}
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(...).
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
