JobConfigHistory plugin can cause startup performance issues

Article ID:360027866992
2 minute readKnowledge base

Issue

This affects any plugin that calls save() from inside it’s constructor, in an environment where an older version of jobConfigHistory plugin is also installed.

The result can be that other plugins fail to load.

For example:

May 06, 2019 5:17:10 PM hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1 error
WARNING: Failed to instantiate Key[type=io.fabric8.jenkins.openshiftsync.GlobalPluginConfiguration, annotation=[none]]; skipping this component
com.google.inject.ProvisionException: Unable to provision, see the following errors:

1) Tried proxying io.fabric8.jenkins.openshiftsync.GlobalPluginConfiguration to support a circular dependency, but it is not an interface.

1 error
    at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:52)
    at com.google.inject.internal.SingletonScope$1.get(SingletonScope.java:145)
    at hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1.get(ExtensionFinder.java:440)
    at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:41)
    at com.google.inject.internal.InjectorImpl$2$1.call(InjectorImpl.java:1016)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1103)
    at com.google.inject.internal.InjectorImpl$2.get(InjectorImpl.java:1012)
    at hudson.ExtensionFinder$GuiceFinder._find(ExtensionFinder.java:402)
    at hudson.ExtensionFinder$GuiceFinder.find(ExtensionFinder.java:393)
    at hudson.ClassicPluginStrategy.findComponents(ClassicPluginStrategy.java:494)
    at hudson.ExtensionList.load(ExtensionList.java:380)
    at hudson.ExtensionList.ensureLoaded(ExtensionList.java:318)
    at hudson.ExtensionList.getComponents(ExtensionList.java:183)
    at hudson.DescriptorExtensionList.load(DescriptorExtensionList.java:192)
    at hudson.ExtensionList.ensureLoaded(ExtensionList.java:318)
    at hudson.ExtensionList.iterator(ExtensionList.java:172)
    at hudson.model.User.allocateDefaultPropertyInstancesAsNeeded(User.java:209)
    at hudson.model.User.load(User.java:198)
    at hudson.model.User.<init>(User.java:191)
    at hudson.model.User.getOrCreateById(User.java:523)
    at hudson.model.User.getById(User.java:619)
    at hudson.model.User.get(User.java:603)
    at hudson.model.User.current(User.java:586)
    at hudson.plugins.jobConfigHistory.PluginUtils.isUserExcluded(PluginUtils.java:120)
    at hudson.plugins.jobConfigHistory.JobConfigHistorySaveableListener.onChange(JobConfigHistorySaveableListener.java:55)
    at hudson.model.listeners.SaveableListener.fireOnChange(SaveableListener.java:81)
    at hudson.model.Descriptor.save(Descriptor.java:878)
    at io.fabric8.jenkins.openshiftsync.GlobalPluginConfiguration.<init>(GlobalPluginConfiguration.java:74)
    at io.fabric8.jenkins.openshiftsync.GlobalPluginConfiguration$$FastClassByGuice$$7bc306ea.newInstance(<generated>)
    at com.google.inject.internal.cglib.reflect.$FastConstructor.newInstance(FastConstructor.java:40)
    at com.google.inject.internal.DefaultConstructionProxyFactory$1.newInstance(DefaultConstructionProxyFactory.java:61)
    at com.google.inject.internal.ConstructorInjector.provision(ConstructorInjector.java:105)
    at com.google.inject.internal.ConstructorInjector.access$000(ConstructorInjector.java:32)
    at com.google.inject.internal.ConstructorInjector$1.call(ConstructorInjector.java:89)
    at com.google.inject.internal.ProvisionListenerStackCallback$Provision.provision(ProvisionListenerStackCallback.java:115)
    at hudson.ExtensionFinder$GuiceFinder$SezpozModule.onProvision(ExtensionFinder.java:567)
    at com.google.inject.internal.ProvisionListenerStackCallback$Provision.provision(ProvisionListenerStackCallback.java:126)
    at com.google.inject.internal.ProvisionListenerStackCallback.provision(ProvisionListenerStackCallback.java:68)
    at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:87)
    at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:267)
    at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1103)
    at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
    at com.google.inject.internal.SingletonScope$1.get(SingletonScope.java:145)
    at hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1.get(ExtensionFinder.java:440)
    at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:41)
    at com.google.inject.internal.InjectorImpl$2$1.call(InjectorImpl.java:1016)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1092)
    at com.google.inject.internal.InjectorImpl$2.get(InjectorImpl.java:1012)
    at hudson.ExtensionFinder$GuiceFinder._find(ExtensionFinder.java:402)
    at hudson.ExtensionFinder$GuiceFinder.find(ExtensionFinder.java:393)
    at hudson.ClassicPluginStrategy.findComponents(ClassicPluginStrategy.java:494)
    at hudson.ExtensionList.load(ExtensionList.java:380)
    at hudson.ExtensionList.ensureLoaded(ExtensionList.java:318)
    at hudson.ExtensionList.iterator(ExtensionList.java:172)
    at jenkins.model.Jenkins.getDescriptorByType(Jenkins.java:1539)
    at com.cloudbees.jenkins.plugins.jsync.archiver.JSyncArtifactManagerFactory.upgrade(JSyncArtifactManagerFactory.java:47)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at hudson.init.TaskMethodFinder.invoke(TaskMethodFinder.java:104)
    at hudson.init.TaskMethodFinder$TaskImpl.run(TaskMethodFinder.java:175)
    at org.jvnet.hudson.reactor.Reactor.runTask(Reactor.java:296)
    at jenkins.model.Jenkins$5.runTask(Jenkins.java:1083)
    at org.jvnet.hudson.reactor.Reactor$2.run(Reactor.java:214)
    at org.jvnet.hudson.reactor.Reactor$Node.run(Reactor.java:117)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

In the above example, openshift-sync-plugin fails to load correctly due to GlobalPluginConfiguration calling save() inside the default constructor:

    at io.fabric8.jenkins.openshiftsync.GlobalPluginConfiguration.<init>(GlobalPluginConfiguration.java:74)

The issue is that the save() above calls the listener from jobConfigHistory plugin:

    at hudson.plugins.jobConfigHistory.PluginUtils.isUserExcluded(PluginUtils.java:120)
    at hudson.plugins.jobConfigHistory.JobConfigHistorySaveableListener.onChange(JobConfigHistorySaveableListener.java:55)

This can cause issues as a user lookup is performed:

    at hudson.model.User.load(User.java:198)

Which can be expensive. It can also cause a deadlock which can prevent Jenkins from completing startup.

Resolution

Upgrade jobConfigHistory plugin to >= 2.19.