[
https://issues.apache.org/jira/browse/SLING-7234?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16288398#comment-16288398
]
Ivo Leitão edited comment on SLING-7234 at 12/12/17 10:43 PM:
--------------------------------------------------------------
Hi,
Well I think I have good news (well sort of :-)). The error disappeared from
the logs and out of 4 restarts only one produced a nasty stracktrace, however
not with this error in particular. Just to give some context I'm working on a
product where we have a lot of bundles (500 +) and what I have noticed is that
as soon as the amount of bundles increases which necessarily means that we have
a higher amount of concurrence, the startup sometimes throws errors from the
framework and / or components. I don't know if this is something related with
karaf in particular or more general but I've certainly seen this behavior in
AEM even in the most recent version (i.e. 6.3).
Anyway, I've uploaded new logs 3 with clean restarts (karaf.clean.x.log) and
one where out of luck I've captured that behavior (karaf.error.1.log).
In that one I'm seeing something that could be another bug in the scripting
core:
017-12-12T22:08:52,830 | ERROR | pool-48-thread-1 | core
| 337 - org.apache.sling.scripting.core - 2.0.53.SNAPSHOT |
[org.apache.sling.scripting.core.impl.ScriptCacheImpl(20)] The deactivate
method has thrown an exception
java.lang.IllegalStateException: Service already unregistered.
at
org.apache.felix.framework.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:140)
[?:?]
at
org.apache.sling.scripting.core.impl.ScriptCacheImpl.deactivate(ScriptCacheImpl.java:277)
[337:org.apache.sling.scripting.core:2.0.53.SNAPSHOT]
Which produces latter an error (multiple ones) in scripting.javascript
2017-12-12T22:08:52,960 | WARN | EventAdminThread #10 |
RhinoJavaScriptEngineFactory | 338 - org.apache.sling.scripting.javascript
- 3.0.2 | addHostObjects: Cannot prepare host object class
org.apache.sling.scripting.javascript.wrapper.ScriptableResource
java.lang.NullPointerException: null
at
org.apache.sling.scripting.javascript.internal.RhinoJavaScriptEngineFactory.addHostObjects(RhinoJavaScriptEngineFactory.java:296)
[338:org.apache.sling.scripting.javascript:3.0.2]
at
org.apache.sling.scripting.javascript.internal.RhinoJavaScriptEngineFactory.getRootScope(RhinoJavaScriptEngineFactory.java:176)
[338:org.apache.sling.scripting.javascript:3.0.2]
at
org.apache.sling.scripting.javascript.internal.RhinoJavaScriptEngineFactory.getScriptEngine(RhinoJavaScriptEngineFactory.java:128)
[338:org.apache.sling.scripting.javascript:3.0.2]
Also another thing of notice but I think this one is less serious, there's an
unclosed resource resolver on i18n (JcrResourceBundleProvider). I've seen this
one a lot of times on other contexts.
2017-12-12T22:08:53,487 | INFO | Apache Sling Resource Resolver Finalizer
Thread | CommonResourceResolverFactoryImpl | 335 -
org.apache.sling.resourceresolver - 1.5.32 | Unclosed ResourceResolver was
created here:
java.lang.Exception: Opening Stacktrace
at
org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl$ResolverReference.<init>(CommonResourceResolverFactoryImpl.java:521)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.register(CommonResourceResolverFactoryImpl.java:218)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.ResourceResolverImpl.<init>(ResourceResolverImpl.java:101)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.ResourceResolverImpl.<init>(ResourceResolverImpl.java:94)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.getResourceResolverInternal(CommonResourceResolverFactoryImpl.java:263)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.getServiceResourceResolver(CommonResourceResolverFactoryImpl.java:396)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.helper.ResourceResolverControl.getResourceTypeResourceResolver(ResourceResolverControl.java:704)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.helper.ResourceResolverControl.getParentResourceType(ResourceResolverControl.java:728)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.ResourceResolverImpl.getParentResourceType(ResourceResolverImpl.java:1219)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.ResourceResolverImpl.isResourceType(ResourceResolverImpl.java:1242)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.api.resource.AbstractResource.isResourceType(AbstractResource.java:121)
[285:org.apache.sling.api:2.16.4]
at
org.apache.sling.i18n.impl.JcrResourceBundleProvider.isDictionaryResource(JcrResourceBundleProvider.java:268)
[310:org.apache.sling.i18n:2.5.10]
Anyway, the error that I was reporting does not appear anymore.
Tnks a lot,
Regards,
Ivo Leitão
was (Author: ivoleitao):
Hi,
Well I think I have good news (well sort of :-)). The error disappeared from
the logs and out of 4 restarts only one produced a nasty stracktrace, however
not with this error in particular. Just to give some context I'm working on a
product where we have a lot of bundles (500 +) and what I have noticed is that
as soon as the amount of bundles increases which necessarily means that we have
a higher amount of concurrence, the startup sometimes throws errors from the
framework and / or components. I don't know if this is something related with
karaf in particular or more general but I've certainly seen this behavior in
AEM even in the most recent version (i.e. 6.3).
Anyway, I've uploaded new logs 3 with clean restarts (karaf.clean.x.log) and
one where out of luck I've captured that behavior (karaf.error.1.log).
In that one I'm seeing something that could be another bug in the scripting
core:
017-12-12T22:08:52,830 | ERROR | pool-48-thread-1 | core
| 337 - org.apache.sling.scripting.core - 2.0.53.SNAPSHOT |
[org.apache.sling.scripting.core.impl.ScriptCacheImpl(20)] The deactivate
method has thrown an exception
java.lang.IllegalStateException: Service already unregistered.
at
org.apache.felix.framework.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:140)
[?:?]
at
org.apache.sling.scripting.core.impl.ScriptCacheImpl.deactivate(ScriptCacheImpl.java:277)
[337:org.apache.sling.scripting.core:2.0.53.SNAPSHOT]
Which produces latter an error (multiple ones) in scripting.javascript
2017-12-12T22:08:52,960 | WARN | EventAdminThread #10 |
RhinoJavaScriptEngineFactory | 338 - org.apache.sling.scripting.javascript
- 3.0.2 | addHostObjects: Cannot prepare host object class
org.apache.sling.scripting.javascript.wrapper.ScriptableResource
java.lang.NullPointerException: null
at
org.apache.sling.scripting.javascript.internal.RhinoJavaScriptEngineFactory.addHostObjects(RhinoJavaScriptEngineFactory.java:296)
[338:org.apache.sling.scripting.javascript:3.0.2]
at
org.apache.sling.scripting.javascript.internal.RhinoJavaScriptEngineFactory.getRootScope(RhinoJavaScriptEngineFactory.java:176)
[338:org.apache.sling.scripting.javascript:3.0.2]
at
org.apache.sling.scripting.javascript.internal.RhinoJavaScriptEngineFactory.getScriptEngine(RhinoJavaScriptEngineFactory.java:128)
[338:org.apache.sling.scripting.javascript:3.0.2]
Also another thing of notice but I think this one is less serious, there's an
unclosed resource resolver on i18n (JcrResourceBundleProvider)
2017-12-12T22:08:53,487 | INFO | Apache Sling Resource Resolver Finalizer
Thread | CommonResourceResolverFactoryImpl | 335 -
org.apache.sling.resourceresolver - 1.5.32 | Unclosed ResourceResolver was
created here:
java.lang.Exception: Opening Stacktrace
at
org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl$ResolverReference.<init>(CommonResourceResolverFactoryImpl.java:521)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.register(CommonResourceResolverFactoryImpl.java:218)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.ResourceResolverImpl.<init>(ResourceResolverImpl.java:101)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.ResourceResolverImpl.<init>(ResourceResolverImpl.java:94)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.getResourceResolverInternal(CommonResourceResolverFactoryImpl.java:263)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.getServiceResourceResolver(CommonResourceResolverFactoryImpl.java:396)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.helper.ResourceResolverControl.getResourceTypeResourceResolver(ResourceResolverControl.java:704)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.helper.ResourceResolverControl.getParentResourceType(ResourceResolverControl.java:728)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.ResourceResolverImpl.getParentResourceType(ResourceResolverImpl.java:1219)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.resourceresolver.impl.ResourceResolverImpl.isResourceType(ResourceResolverImpl.java:1242)
[335:org.apache.sling.resourceresolver:1.5.32]
at
org.apache.sling.api.resource.AbstractResource.isResourceType(AbstractResource.java:121)
[285:org.apache.sling.api:2.16.4]
at
org.apache.sling.i18n.impl.JcrResourceBundleProvider.isDictionaryResource(JcrResourceBundleProvider.java:268)
[310:org.apache.sling.i18n:2.5.10]
Anyway, the error that I was reporting does not appear anymore.
Tnks a lot,
Regards,
Ivo Leitão
> ServiceFactory.getService() resulted in a cycle in sling karaf
> ---------------------------------------------------------------
>
> Key: SLING-7234
> URL: https://issues.apache.org/jira/browse/SLING-7234
> Project: Sling
> Issue Type: Bug
> Components: Karaf, Scripting
> Affects Versions: Scripting Core 2.0.50
> Environment: Debian linux, jdk 1.8.0_151-b12
> Reporter: Ivo Leitão
> Assignee: Oliver Lietz
> Attachments: clean.log.1, grep-errors.log, karaf.clean.1.log,
> karaf.clean.2.log, karaf.clean.3.log, karaf.errors.log, sample.log.1
>
>
> Hello,
> Once in a while on the first startup of Sling on Karaf I'm seeing the
> exception ServiceFactory.getService() resulted in a cycle. This does not
> happen every time only on some startups.
> After the first startup on the next restart this exception does not appear
> anymore.
> I've picked a sample of the exception. Unfortunately this seems like a
> concurrency issue and therefore much harder to find a pattern but it happens
> mostly with sling scripting. I've seen other exceptions also with sling
> scripting but this one is the most common
> I've uploaded two log files:
> clean.log.1 with a clean startup and
> sample.log.1 with the aforementioned exception
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
