[
https://issues.apache.org/jira/browse/SLING-3913?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Chetan Mehrotra updated SLING-3913:
-----------------------------------
Description:
Logging fails to work initially in SAP NetWeaver environment which run on top
of OSGi using Eclipse Virgo which already use Logback. Following error is seen
in app server logs. Note that evetually later logging does work, just that
initial few logs which are generated before Sling Logging bundle gets started
are lost
{noformat}
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##Reported
exception:|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##java.lang.ClassNotFoundException:
org.eclipse.virgo.medic.log.logback.DelegatingContextSelector not found by
org.apache.sling.commons.log [14]|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.BundleWiringImpl.findClassOrResourceByDelegation(BundleWiringImpl.java:1550)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.BundleWiringImpl.access$400(BundleWiringImpl.java:77)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1973)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at java.lang.ClassLoader.loadClass(ClassLoader.java:415)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at java.lang.Class.forName0(Native Method)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at java.lang.Class.forName(Class.java:186)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at ch.qos.logback.core.util.Loader.loadClass(Loader.java:185)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
ch.qos.logback.classic.util.ContextSelectorStaticBinder.dynamicalContextSelector(ContextSelectorStaticBinder.java:97)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
ch.qos.logback.classic.util.ContextSelectorStaticBinder.init(ContextSelectorStaticBinder.java:72)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:93)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.sling.installer.provider.file.impl.ServicesListener.<init>(ServicesListener.java:45)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.sling.installer.provider.file.impl.Activator.start(Activator.java:66)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.util.SecureAction.startActivator(SecureAction.java:645)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.apache.felix.framework.Felix.activateBundle(Felix.java:2152)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.apache.felix.framework.Felix.startBundle(Felix.java:2070)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1297)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:304)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at java.lang.Thread.run(Thread.java:789)|
2014 09 04
06:48:05#+00#INFO#System.out##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##Attempting
to load ESAPI.properties via file I/O.|
{noformat}
Logback has some [discovery
mechanism|http://logback.qos.ch/manual/contextSelector.html] where it looks
for a system property {{logback.ContextSelector}} and loads the configured
class if set. As SAP NetWeaver Cloud internally uses Eclipse Virgo which also
uses Logback it has set a value for that system property and that causes the
issue.
As a fix we should disable this discovery logic in Logback
was:
Logging fails to work in SAP NetWeaver environment which run on top of OSGi
using Eclipse Virgo which already use Logback. Following error is seen in app
server logs
{noformat}
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##Reported
exception:|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##java.lang.ClassNotFoundException:
org.eclipse.virgo.medic.log.logback.DelegatingContextSelector not found by
org.apache.sling.commons.log [14]|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.BundleWiringImpl.findClassOrResourceByDelegation(BundleWiringImpl.java:1550)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.BundleWiringImpl.access$400(BundleWiringImpl.java:77)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1973)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at java.lang.ClassLoader.loadClass(ClassLoader.java:415)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at java.lang.Class.forName0(Native Method)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at java.lang.Class.forName(Class.java:186)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at ch.qos.logback.core.util.Loader.loadClass(Loader.java:185)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
ch.qos.logback.classic.util.ContextSelectorStaticBinder.dynamicalContextSelector(ContextSelectorStaticBinder.java:97)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
ch.qos.logback.classic.util.ContextSelectorStaticBinder.init(ContextSelectorStaticBinder.java:72)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:93)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.sling.installer.provider.file.impl.ServicesListener.<init>(ServicesListener.java:45)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.sling.installer.provider.file.impl.Activator.start(Activator.java:66)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.util.SecureAction.startActivator(SecureAction.java:645)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.apache.felix.framework.Felix.activateBundle(Felix.java:2152)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.apache.felix.framework.Felix.startBundle(Felix.java:2070)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1297)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at
org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:304)|
2014 09 04
06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
at java.lang.Thread.run(Thread.java:789)|
2014 09 04
06:48:05#+00#INFO#System.out##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##Attempting
to load ESAPI.properties via file I/O.|
{noformat}
Logback has some [discovery
mechanism|http://logback.qos.ch/manual/contextSelector.html] where it looks
for a system property {{logback.ContextSelector}} and loads the configured
class if set. As SAP NetWeaver Cloud internally uses Eclipse Virgo which also
uses Logback it has set a value for that system property and that causes the
issue.
As a fix we should disable this discovery logic in Logback
> Sling Logging fails to work in Eclipse Virgo
> --------------------------------------------
>
> Key: SLING-3913
> URL: https://issues.apache.org/jira/browse/SLING-3913
> Project: Sling
> Issue Type: Bug
> Components: Commons
> Affects Versions: Commons Log 4.0.0
> Reporter: Chetan Mehrotra
> Assignee: Chetan Mehrotra
> Fix For: Commons Log 4.0.2
>
>
> Logging fails to work initially in SAP NetWeaver environment which run on top
> of OSGi using Eclipse Virgo which already use Logback. Following error is
> seen in app server logs. Note that evetually later logging does work, just
> that initial few logs which are generated before Sling Logging bundle gets
> started are lost
> {noformat}
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##Reported
> exception:|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##java.lang.ClassNotFoundException:
> org.eclipse.virgo.medic.log.logback.DelegatingContextSelector not found by
> org.apache.sling.commons.log [14]|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.apache.felix.framework.BundleWiringImpl.findClassOrResourceByDelegation(BundleWiringImpl.java:1550)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.apache.felix.framework.BundleWiringImpl.access$400(BundleWiringImpl.java:77)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1973)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at java.lang.ClassLoader.loadClass(ClassLoader.java:415)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at java.lang.Class.forName0(Native Method)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at java.lang.Class.forName(Class.java:186)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at ch.qos.logback.core.util.Loader.loadClass(Loader.java:185)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> ch.qos.logback.classic.util.ContextSelectorStaticBinder.dynamicalContextSelector(ContextSelectorStaticBinder.java:97)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> ch.qos.logback.classic.util.ContextSelectorStaticBinder.init(ContextSelectorStaticBinder.java:72)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:93)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.apache.sling.installer.provider.file.impl.ServicesListener.<init>(ServicesListener.java:45)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.apache.sling.installer.provider.file.impl.Activator.start(Activator.java:66)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.apache.felix.framework.util.SecureAction.startActivator(SecureAction.java:645)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at org.apache.felix.framework.Felix.activateBundle(Felix.java:2152)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at org.apache.felix.framework.Felix.startBundle(Felix.java:2070)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1297)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at
> org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:304)|
> 2014 09 04
> 06:43:32#+00#ERROR#System.err##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##
> at java.lang.Thread.run(Thread.java:789)|
> 2014 09 04
> 06:48:05#+00#INFO#System.out##anonymous#FelixStartLevel##adsdev#deployedauthor1#web##Attempting
> to load ESAPI.properties via file I/O.|
> {noformat}
> Logback has some [discovery
> mechanism|http://logback.qos.ch/manual/contextSelector.html] where it looks
> for a system property {{logback.ContextSelector}} and loads the configured
> class if set. As SAP NetWeaver Cloud internally uses Eclipse Virgo which also
> uses Logback it has set a value for that system property and that causes the
> issue.
> As a fix we should disable this discovery logic in Logback
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
