[
https://issues.apache.org/jira/browse/FELIX-6108?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Tobias Gunkel updated FELIX-6108:
---------------------------------
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:
{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(...).
was:
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(...).
> 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
> Priority: Major
> Labels: log
>
> 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:
> {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)
