Startup deadlock when using a GlobalConfiguration + Initializer < JOB_LOADED

31 views
Skip to first unread message

Julien HENRY

unread,
Apr 10, 2018, 4:39:35 AM4/10/18
to Jenkins Developers
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)

Daniel Beck

unread,
Apr 10, 2018, 5:35:13 AM4/10/18
to jenkin...@googlegroups.com

> On 10. Apr 2018, at 10:39, Julien HENRY <julien...@sonarsource.com> 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!

Julien HENRY

unread,
Apr 10, 2018, 5:52:27 AM4/10/18
to jenkin...@googlegroups.com
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


--
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 jenkinsci-dev+unsubscribe@googlegroups.com.
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.

Daniel Beck

unread,
Apr 10, 2018, 5:59:30 AM4/10/18
to jenkin...@googlegroups.com

> On 10. Apr 2018, at 11:51, Julien HENRY <julien...@sonarsource.com> 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…?

Julien HENRY

unread,
Apr 10, 2018, 6:26:29 AM4/10/18
to jenkin...@googlegroups.com
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

--
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 jenkinsci-dev+unsubscribe@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/486CA78C-5D51-4FF3-AE39-021CC3499A17%40beckweb.net.

Baptiste Mathus

unread,
Apr 10, 2018, 8:03:43 AM4/10/18
to Jenkins Developers

--
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 jenkinsci-dev+unsubscribe@googlegroups.com.
 To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-dev/CAD9wyxE%3DmHzo8SQtLhb9ReNQo4ngkMUj8bJkLeMEzbAVVC79UA%40mail.gmail.com.

Jesse Glick

unread,
Apr 10, 2018, 10:03:00 AM4/10/18
to Jenkins Dev
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.
Reply all
Reply to author
Forward
0 new messages