Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
7 messages Options
Reply | Threaded
Open this post in threaded view
|

Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

Julien HENRY-2
Hi,

Our plugin uses a GlobalConfiguration extension, and to migrate old data, we added an Initializer.

Following the javadoc of Initializer, I set after=PLUGINS_PREPARED

@Extension
public class MyGlobalConfiguration extends GlobalConfiguration {

  public MyGlobalConfiguration() {
    load();
  }

  @Initializer(after = InitMilestone.PLUGINS_PREPARED)
  public void migrateData() {
    // ...
  }

}

But this lead to a startup deadlock.

"GitSCM.onLoaded":
 waiting for ownable synchronizer 0x0000000085777f80, (a java/util/concurrent/locks/ReentrantLock$NonfairSync),
 which is held by "MyGlobalConfiguration.migrateData"
"MyGlobalConfiguration.migrateData":
  waiting to lock Monitor@0x00007f9ef0282808 (Object@0x0000000084f2b888, a hudson/ExtensionList$Lock),
  which is held by "GitSCM.onLoaded"

Seems that the OldDataMonitor is somehow involed in the deadlock (see stack traces).

After spending a lot of time on it, I found the solution in the logstash plugin: change the Initializer to after=JOB_LOADED

Could it be possible to improve the situation, by at least completing the Javadoc, or maybe detecting and failing fast when a GlobalConfiguration tries to use an Initializer earlier than JOB_LOADED ?

Thread 5233: (state = BLOCKED)
 - hudson.ExtensionList.ensureLoaded() @bci=40, line=303 (Interpreted frame)
 - hudson.ExtensionList.iterator() @bci=6, line=158 (Interpreted frame)
 - jenkins.model.Jenkins.getAdministrativeMonitor(java.lang.String) @bci=4, line=2109 (Interpreted frame)
 - hudson.diagnosis.OldDataMonitor.get(jenkins.model.Jenkins) @bci=3, line=82 (Interpreted frame)
 - hudson.diagnosis.OldDataMonitor.report(hudson.model.Saveable, java.util.Collection) @bci=196, line=217 (Interpreted frame)
 - hudson.util.RobustReflectionConverter.doUnmarshal(java.lang.Object, com.thoughtworks.xstream.io.HierarchicalStreamReader, com.thoughtworks.xstream.converters.UnmarshallingContext) @bci=734, line=371 (Interpreted frame)
 - hudson.util.RobustReflectionConverter.unmarshal(com.thoughtworks.xstream.io.HierarchicalStreamReader, com.thoughtworks.xstream.converters.UnmarshallingContext) @bci=11, line=270 (Interpreted frame)
 - com.thoughtworks.xstream.core.TreeUnmarshaller.convert(java.lang.Object, java.lang.Class, com.thoughtworks.xstream.converters.Converter) @bci=15, line=72 (Interpreted frame)
 - com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(java.lang.Object, java.lang.Class, com.thoughtworks.xstream.converters.Converter) @bci=175, line=65 (Interpreted frame)
 - com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(java.lang.Object, java.lang.Class, com.thoughtworks.xstream.converters.Converter) @bci=82, line=66 (Interpreted frame)
 - com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(java.lang.Object, java.lang.Class) @bci=4, line=50 (Interpreted frame)
 - com.thoughtworks.xstream.core.TreeUnmarshaller.start(com.thoughtworks.xstream.converters.DataHolder) @bci=20, line=134 (Interpreted frame)
 - com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(java.lang.Object, com.thoughtworks.xstream.io.HierarchicalStreamReader, com.thoughtworks.xstream.converters.DataHolder, com.thoughtworks.xstream.converters.ConverterLookup, com.thoughtworks.xstream.mapper.Mapper) @bci=15, line=32 (Interpreted frame)
 - com.thoughtworks.xstream.XStream.unmarshal(com.thoughtworks.xstream.io.HierarchicalStreamReader, java.lang.Object, com.thoughtworks.xstream.converters.DataHolder) @bci=15, line=1189 (Interpreted frame)
 - hudson.util.XStream2.unmarshal(com.thoughtworks.xstream.io.HierarchicalStreamReader, java.lang.Object, com.thoughtworks.xstream.converters.DataHolder, boolean) @bci=54, line=160 (Interpreted frame)
 - hudson.util.XStream2.unmarshal(com.thoughtworks.xstream.io.HierarchicalStreamReader, java.lang.Object, com.thoughtworks.xstream.converters.DataHolder) @bci=5, line=131 (Interpreted frame)
 - com.thoughtworks.xstream.XStream.unmarshal(com.thoughtworks.xstream.io.HierarchicalStreamReader, java.lang.Object) @bci=4, line=1173 (Interpreted frame)
 - hudson.XmlFile.unmarshal(java.lang.Object, boolean) @bci=102, line=178 (Interpreted frame)
 - hudson.XmlFile.unmarshal(java.lang.Object) @bci=3, line=161 (Interpreted frame)
 - hudson.model.Descriptor.load() @bci=15, line=893 (Interpreted frame)
 - hudson.plugins.sonar.MyGlobalConfiguration.<init>() @bci=18, line=49 (Interpreted frame)
 - hudson.plugins.sonar.MyGlobalConfiguration$$FastClassByGuice$$9ca8165c.newInstance(int, java.lang.Object[]) @bci=24 (Interpreted frame)
 - com.google.inject.internal.cglib.reflect.$FastConstructor.newInstance(java.lang.Object[]) @bci=9, line=40 (Interpreted frame)
 - com.google.inject.internal.DefaultConstructionProxyFactory$1.newInstance(java.lang.Object[]) @bci=5, line=61 (Interpreted frame)
 - com.google.inject.internal.ConstructorInjector.provision(com.google.inject.internal.Errors, com.google.inject.internal.InternalContext, com.google.inject.internal.ConstructionContext) @bci=17, line=105 (Interpreted frame)
 - com.google.inject.internal.ConstructorInjector.construct(com.google.inject.internal.Errors, com.google.inject.internal.InternalContext, java.lang.Class, com.google.inject.internal.ProvisionListenerStackCallback) @bci=60, line=85 (Interpreted frame)
 - com.google.inject.internal.ConstructorBindingImpl$Factory.get(com.google.inject.internal.Errors, com.google.inject.internal.InternalContext, com.google.inject.spi.Dependency, boolean) @bci=61, line=267 (Interpreted frame)
 - com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(com.google.inject.internal.InternalContext) @bci=19, line=46 (Interpreted frame)
 - com.google.inject.internal.InjectorImpl.callInContext(com.google.inject.internal.ContextualCallable) @bci=152, line=1103 (Interpreted frame)
 - com.google.inject.internal.ProviderToInternalFactoryAdapter.get() @bci=21, line=40 (Interpreted frame)
 - com.google.inject.internal.SingletonScope$1.get() @bci=39, line=145 (Interpreted frame)
 - hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1.get() @bci=4, line=424 (Interpreted frame)
 - com.google.inject.internal.InternalFactoryToProviderAdapter.get(com.google.inject.internal.Errors, com.google.inject.internal.InternalContext, com.google.inject.spi.Dependency, boolean) @bci=5, line=41 (Interpreted frame)
 - com.google.inject.internal.InjectorImpl$2$1.call(com.google.inject.internal.InternalContext) @bci=45, line=1016 (Interpreted frame)
 - com.google.inject.internal.InjectorImpl.callInContext(com.google.inject.internal.ContextualCallable) @bci=75, line=1092 (Interpreted frame)
 - com.google.inject.internal.InjectorImpl$2.get() @bci=25, line=1012 (Interpreted frame)
 - com.google.inject.internal.InjectorImpl.getInstance(java.lang.Class) @bci=5, line=1051 (Interpreted frame)
 - jenkins.ProxyInjector.getInstance(java.lang.Class) @bci=5, line=98 (Interpreted frame)
 - hudson.init.TaskMethodFinder.lookUp(java.lang.Class) @bci=49, line=124 (Interpreted frame)
 - hudson.init.TaskMethodFinder.invoke(java.lang.reflect.Method) @bci=59, line=105 (Interpreted frame)
 - hudson.init.TaskMethodFinder$TaskImpl.run(org.jvnet.hudson.reactor.Reactor) @bci=8, line=175 (Interpreted frame)
 - org.jvnet.hudson.reactor.Reactor.runTask(org.jvnet.hudson.reactor.Task) @bci=2, line=296 (Interpreted frame)
 - jenkins.model.Jenkins$5.runTask(org.jvnet.hudson.reactor.Task) @bci=57, line=1064 (Interpreted frame)
 - org.jvnet.hudson.reactor.Reactor$2.run() @bci=24, line=214 (Interpreted frame)
 - org.jvnet.hudson.reactor.Reactor$Node.run() @bci=4, line=117 (Interpreted frame)
 - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=95, line=1149 (Interpreted frame)
 - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=624 (Interpreted frame)
 - java.lang.Thread.run() @bci=11, line=748 (Interpreted frame)

Thread 5229: (state = BLOCKED)
 - sun.misc.Unsafe.park(boolean, long) @bci=0 (Interpreted frame)
 - java.util.concurrent.locks.LockSupport.park(java.lang.Object) @bci=14, line=175 (Interpreted frame)
 - java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt() @bci=1, line=836 (Interpreted frame)
 - java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.util.concurrent.locks.AbstractQueuedSynchronizer$Node, int) @bci=67, line=870 (Interpreted frame)
 - java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(int) @bci=17, line=1199 (Compiled frame)
 - java.util.concurrent.locks.ReentrantLock$NonfairSync.lock() @bci=21, line=209 (Compiled frame)
 - java.util.concurrent.locks.ReentrantLock.lock() @bci=4, line=285 (Compiled frame)
 - com.google.inject.internal.CycleDetectingLock$CycleDetectingLockFactory$ReentrantCycleDetectingLock.lockOrDetectPotentialLocksCycle() @bci=73, line=160 (Compiled frame)
 - com.google.inject.internal.SingletonScope$1.get() @bci=13, line=136 (Compiled frame)
 - hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1.get() @bci=4, line=424 (Compiled frame)
 - com.google.inject.internal.InternalFactoryToProviderAdapter.get(com.google.inject.internal.Errors, com.google.inject.internal.InternalContext, com.google.inject.spi.Dependency, boolean) @bci=5, line=41 (Compiled frame)
 - com.google.inject.internal.InjectorImpl$2$1.call(com.google.inject.internal.InternalContext) @bci=45, line=1016 (Compiled frame)
 - com.google.inject.internal.InjectorImpl.callInContext(com.google.inject.internal.ContextualCallable) @bci=75, line=1092 (Compiled frame)
 - com.google.inject.internal.InjectorImpl$2.get() @bci=25, line=1012 (Compiled frame)
 - hudson.ExtensionFinder$GuiceFinder._find(java.lang.Class, java.util.List, com.google.inject.Injector) @bci=99, line=386 (Interpreted frame)
 - hudson.ExtensionFinder$GuiceFinder.find(java.lang.Class, hudson.model.Hudson) @bci=24, line=377 (Interpreted frame)
 - hudson.ClassicPluginStrategy.findComponents(java.lang.Class, hudson.model.Hudson) @bci=155, line=482 (Interpreted frame)
 - hudson.ExtensionList.load() @bci=68, line=366 (Interpreted frame)
 - hudson.ExtensionList.ensureLoaded() @bci=48, line=304 (Interpreted frame)
 - hudson.ExtensionList.iterator() @bci=6, line=158 (Interpreted frame)
 - jenkins.model.Jenkins.getDescriptorByType(java.lang.Class) @bci=7, line=1520 (Interpreted frame)
 - hudson.plugins.git.GitSCM.onLoaded() @bci=22, line=1859 (Interpreted frame)
 - sun.reflect.NativeMethodAccessorImpl.invoke0(java.lang.reflect.Method, java.lang.Object, java.lang.Object[]) @bci=0 (Interpreted frame)
 - sun.reflect.NativeMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=100, line=62 (Interpreted frame)
 - sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=6, line=43 (Compiled frame)
 - java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) @bci=56, line=498 (Compiled frame)
 - hudson.init.TaskMethodFinder.invoke(java.lang.reflect.Method) @bci=63, line=104 (Interpreted frame)
 - hudson.init.TaskMethodFinder$TaskImpl.run(org.jvnet.hudson.reactor.Reactor) @bci=8, line=175 (Interpreted frame)
 - org.jvnet.hudson.reactor.Reactor.runTask(org.jvnet.hudson.reactor.Task) @bci=2, line=296 (Interpreted frame)
 - jenkins.model.Jenkins$5.runTask(org.jvnet.hudson.reactor.Task) @bci=57, line=1064 (Interpreted frame)
 - org.jvnet.hudson.reactor.Reactor$2.run() @bci=24, line=214 (Interpreted frame)
 - org.jvnet.hudson.reactor.Reactor$Node.run() @bci=4, line=117 (Interpreted frame)
 - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=95, line=1149 (Interpreted frame)
 - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=624 (Interpreted frame)
 - java.lang.Thread.run() @bci=11, line=748 (Interpreted frame)

--
You received this message because you are subscribed to the Google Groups "Jenkins Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/75360c3f-3d96-4f82-a77c-bbd4261b4268%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

Daniel Beck

> On 10. Apr 2018, at 10:39, Julien HENRY <[hidden email]> wrote:
>
> Could it be possible to improve the situation, by at least completing the Javadoc, or maybe detecting and failing fast when a GlobalConfiguration tries to use an Initializer earlier than JOB_LOADED ?
>

It probably depends on what your initializer does.

I understand the Javadoc to mean that it needs to be PLUGINS_PREPARED _or later_ -- if that (or something similar) would have helped, just file a PR to core. Thanks!

--
You received this message because you are subscribed to the Google Groups "Jenkins Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/61B2D983-17C5-42B8-86D4-731E7E2F5D04%40beckweb.net.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

Julien HENRY-2
The deadlock seems to occurs whatever is in the method annotated by @Initializer. We tried to put a log at the very beginning of the method and it was never called.

If you look at the stacktraces, the deadlock occurs in the constructor of the GlobalConfiguration, because it ends up calling OldDataMonitor that itself access ExtensionList, and that seems to conflict with other plugins like GitSCM that also access ExtensionList from its Initializer.

Julien Henry | SonarSource

Developer

https://sonarsource.com


2018-04-10 11:35 GMT+02:00 Daniel Beck <[hidden email]>:

> On 10. Apr 2018, at 10:39, Julien HENRY <[hidden email]> wrote:
>
> Could it be possible to improve the situation, by at least completing the Javadoc, or maybe detecting and failing fast when a GlobalConfiguration tries to use an Initializer earlier than JOB_LOADED ?
>

It probably depends on what your initializer does.

I understand the Javadoc to mean that it needs to be PLUGINS_PREPARED _or later_ -- if that (or something similar) would have helped, just file a PR to core. Thanks!

--
You received this message because you are subscribed to a topic in the Google Groups "Jenkins Developers" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/jenkinsci-dev/hyMmQ-eDDVo/unsubscribe.
To unsubscribe from this group and all its topics, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/61B2D983-17C5-42B8-86D4-731E7E2F5D04%40beckweb.net.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "Jenkins Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/CAD9wyxGDa17qejsfe_qYGX-Ew%3DFYQjQFKgKW7jmfNhk1R1Y9fg%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

Daniel Beck

> On 10. Apr 2018, at 11:51, Julien HENRY <[hidden email]> wrote:
>
> If you look at the stacktraces, the deadlock occurs in the constructor of the GlobalConfiguration, because it ends up calling OldDataMonitor that itself access ExtensionList, and that seems to conflict with other plugins like GitSCM that also access ExtensionList from its Initializer.


Right, so in this case it depends on the class you extend. More convoluted, but still doesn't look like it can never be earlier than JOB_LOADED…?

--
You received this message because you are subscribed to the Google Groups "Jenkins Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/486CA78C-5D51-4FF3-AE39-021CC3499A17%40beckweb.net.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

Julien HENRY-2
My point was to clarify the specific case of GlobalConfiguration. I'm not pretending any Initializer should be after JOB_LOADED.

The deadlock was sneaky, because it can only be reproduced if you have previous config data. So we haven't spotted it during our tests (because we start from a clean env) and we ended up releasing something broken.

Julien Henry | SonarSource

Developer

https://sonarsource.com


2018-04-10 11:59 GMT+02:00 Daniel Beck <[hidden email]>:

> On 10. Apr 2018, at 11:51, Julien HENRY <[hidden email]> wrote:
>
> If you look at the stacktraces, the deadlock occurs in the constructor of the GlobalConfiguration, because it ends up calling OldDataMonitor that itself access ExtensionList, and that seems to conflict with other plugins like GitSCM that also access ExtensionList from its Initializer.


Right, so in this case it depends on the class you extend. More convoluted, but still doesn't look like it can never be earlier than JOB_LOADED…?

--
You received this message because you are subscribed to a topic in the Google Groups "Jenkins Developers" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/jenkinsci-dev/hyMmQ-eDDVo/unsubscribe.
To unsubscribe from this group and all its topics, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/486CA78C-5D51-4FF3-AE39-021CC3499A17%40beckweb.net.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "Jenkins Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/CAD9wyxE%3DmHzo8SQtLhb9ReNQo4ngkMUj8bJkLeMEzbAVVC79UA%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

Baptiste MATHUS

2018-04-10 12:26 GMT+02:00 Julien HENRY <[hidden email]>:
My point was to clarify the specific case of GlobalConfiguration. I'm not pretending any Initializer should be after JOB_LOADED.

The deadlock was sneaky, because it can only be reproduced if you have previous config data. So we haven't spotted it during our tests (because we start from a clean env) and we ended up releasing something broken.

Julien Henry | SonarSource

Developer

https://sonarsource.com


2018-04-10 11:59 GMT+02:00 Daniel Beck <[hidden email]>:

> On 10. Apr 2018, at 11:51, Julien HENRY <[hidden email]> wrote:
>
> If you look at the stacktraces, the deadlock occurs in the constructor of the GlobalConfiguration, because it ends up calling OldDataMonitor that itself access ExtensionList, and that seems to conflict with other plugins like GitSCM that also access ExtensionList from its Initializer.


Right, so in this case it depends on the class you extend. More convoluted, but still doesn't look like it can never be earlier than JOB_LOADED…?

--
You received this message because you are subscribed to a topic in the Google Groups "Jenkins Developers" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/jenkinsci-dev/hyMmQ-eDDVo/unsubscribe.
To unsubscribe from this group and all its topics, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/486CA78C-5D51-4FF3-AE39-021CC3499A17%40beckweb.net.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "Jenkins Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/CAD9wyxE%3DmHzo8SQtLhb9ReNQo4ngkMUj8bJkLeMEzbAVVC79UA%40mail.gmail.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "Jenkins Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/CANWgJS4rwYnx04eYiLLD5BvfNk_N7EZ2T9BV3xppkNKJc3zJ0g%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

Jesse Glick-4
In reply to this post by Julien HENRY-2
While changing the initializer settings may have happened to solve the
issue in this case, the advice is not generally applicable. Use
JENKINS-50663 for discussion.

--
You received this message because you are subscribed to the Google Groups "Jenkins Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/CANfRfr1B6WZMdo2DHVYdETSTXiaomQKsPKqcg-UVnzAMfDbLPA%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.