-
Bug
-
Resolution: Fixed
-
Major
-
None
We run Jenkins with 9000 jobs in production environment. A few days ago, we run into a serious problem. Jenkins service was stuck in activating state, the UI was reachable from browser, but it was just saying "Wait Until Jenkins Get Ready". There were "SEVERE" logs and we tried to debug according to them but none of those worked.
So, the problem was solved by renaming 'Jobs' folder to 'jobsbak' (a temporary folder) and 'jobsbak' to 'Jobs' again. When we rename the folder Jenkins created an empty 'Jobs' folder. After this Jenkins started with 0 jobs. Then we stopped the service and rename 'jobsbak' to 'Jobs'. It worked again.
The problem continues, because in every Jenkins restart the problem still occurs and we want a proper solution for it.
I'm sharing the logs. "The unable to read xml file" WARNING log might be related to this problem, but i'm not sure. There is one example of this log here, but in the main log file it occurs frequently
SEVERE logs are;
2024-02-18 10:47:37.985+0000 [id=56] SEVERE o.a.s.c.u.logging.LoggingUtils#error: bind(0.0.0.0/0.0.0.0:22) - failed (SocketException) to bind: Permission denied
2024-02-18 10:47:37.990+0000 [id=56] SEVERE jenkins.InitReactorRunner$1#onTaskFailed: Failed SSHD.init
2024-02-18 10:47:40.985+0000 [id=30] SEVERE h.p.g.b.GlobalBuildStatsPluginSaver#reloadPlugin: Unable to read /hdd2/jenkins/global-build-stats.xml
2024-02-18 10:47:51.303+0000 [id=30] SEVERE o.j.p.s.s.ScriptApproval$ApprovedWhitelist#<init>: Malformed signature entry in scriptApproval.xml: 'Method jenkins.model.Jenkins getItemByFullName'
2024-02-18 10:48:02.500+0000 [id=1093] SEVERE c.m.t.j.internal.auth.NativeAuth#nativeAuthConfigure: Could not load GSSAPI library, Kerberos authentication disabled.
And some of INFO and WARNING logs are;
2024-02-18 15:08:01.775+0000 [id=69] INFO j.a.PrioritySorterPlugin#init2: Sorting existing Queue ...
2024-02-18 15:08:01.787+0000 [id=69] INFO j.a.sorter.AdvancedQueueSorter#init: Initialized the QueueSorter with 0 Buildable Items
2024-02-18 15:08:01.790+0000 [id=74] INFO jenkins.InitReactorRunner$1#onAttained: Configuration for all jobs updated
2024-02-18 15:08:01.800+0000 [id=1024] INFO hudson.model.AsyncPeriodicWork#lambda$doRun$1: Started Download metadata
2024-02-18 15:08:01.806+0000 [id=1024] INFO hudson.model.AsyncPeriodicWork#lambda$doRun$1: Finished Download metadata. 3 ms
2024-02-18 15:08:01.841+0000 [id=110] WARNING o.j.c.p.PersistentBuildQueue#getPersistentBuildQueueEntries: /hdd2/jenkins/org.jenkins.ci.plugins.PersistentBuildQueue.txt (No such file or directory)
java.io.FileNotFoundException: /hdd2/jenkins/org.jenkins.ci.plugins.PersistentBuildQueue.txt (No such file or directory)
at java.io.FileInputStream.open0(Native Method)
at java.io.FileInputStream.open(FileInputStream.java:195)
at java.io.FileInputStream.<init>(FileInputStream.java:138)
at org.jenkins.ci.plugins.PersistentBuildQueue.getPersistentBuildQueueEntries(PersistentBuildQueue.java:111)
at org.jenkins.ci.plugins.PersistentBuildQueue.load(PersistentBuildQueue.java:131)
at org.jenkins.ci.plugins.PersistentBuildQueuePeriodicWork.doRun(PersistentBuildQueuePeriodicWork.java:43)
at hudson.triggers.SafeTimerTask.run(SafeTimerTask.java:92)
at jenkins.security.ImpersonatingScheduledExecutorService$1.run(ImpersonatingScheduledExecutorService.java:67)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
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:750)
2024-02-18 15:08:02.171+0000 [id=60] INFO h.p.s.ScmSyncConfigurationBusiness#queueChangeSet: Queue of changeset A config.xml
aborted (scm manipulator not settled !)
2024-02-18 15:08:02.214+0000 [id=90] SEVERE o.a.s.c.u.logging.LoggingUtils#error: bind(0.0.0.0/0.0.0.0:22) - failed (SocketException) to bind: Permission denied
2024-02-18 15:08:02.219+0000 [id=90] SEVERE jenkins.InitReactorRunner$1#onTaskFailed: Failed SSHD.init
java.net.SocketException: Permission denied
at sun.nio.ch.Net.bind0(Native Method)
at sun.nio.ch.Net.bind(Net.java:461)
at sun.nio.ch.Net.bind(Net.java:453)
at sun.nio.ch.AsynchronousServerSocketChannelImpl.bind(AsynchronousServerSocketChannelImpl.java:163)
at org.apache.sshd.common.io.nio2.Nio2Acceptor.bind(Nio2Acceptor.java:81)
at org.apache.sshd.common.io.nio2.Nio2Acceptor.bind(Nio2Acceptor.java:171)
at org.apache.sshd.server.SshServer.start(SshServer.java:340)
at org.jenkinsci.main.modules.sshd.SSHD.start(SSHD.java:180)
at org.jenkinsci.main.modules.sshd.SSHD.init(SSHD.java:268)
Caused: java.lang.reflect.InvocationTargetException
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:109)
Caused: java.lang.Error
at hudson.init.TaskMethodFinder.invoke(TaskMethodFinder.java:115)
at hudson.init.TaskMethodFinder$TaskImpl.run(TaskMethodFinder.java:185)
at org.jvnet.hudson.reactor.Reactor.runTask(Reactor.java:305)
at jenkins.model.Jenkins$5.runTask(Jenkins.java:1156)
at org.jvnet.hudson.reactor.Reactor$2.run(Reactor.java:222)
at org.jvnet.hudson.reactor.Reactor$Node.run(Reactor.java:121)
at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:68)
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:750)
2024-02-18 15:08:04.296+0000 [id=93] INFO jenkins.InitReactorRunner$1#onAttained: Completed initialization
2024-02-18 15:08:04.352+0000 [id=30] INFO h.p.s.ScmSyncConfigurationBusiness#queueChangeSet: Queue of changeset A config.xml
aborted (scm manipulator not settled !)
2024-02-18 15:08:04.525+0000 [id=30] WARNING j.branch.WorkspaceLocatorImpl#getWorkspaceRoot:JENKINS-2111path sanitization ineffective when using legacy Workspace Root Directory ‘${ITEM_ROOTDIR}/workspace’; switch to ‘${JENKINS_HOME}/workspace/${ITEM_FULL_NAME}’ as inJENKINS-8446/ JENKINS-21942
2024-02-18 15:08:04.558+0000 [id=30] SEVERE h.p.g.b.GlobalBuildStatsPluginSaver#reloadPlugin: Unable to read /hdd2/jenkins/global-build-stats.xml
java.lang.NullPointerException
at java.util.ArrayList.addAll(ArrayList.java:583)
at hudson.plugins.global_build_stats.model.JobBuildResultSharder.load(JobBuildResultSharder.java:143)
at hudson.plugins.global_build_stats.xstream.migration.AbstractMigrator.readGlobalBuildStatsPOJO(AbstractMigrator.java:35)
at hudson.plugins.global_build_stats.xstream.GlobalBuildStatsXStreamConverter.unmarshal(GlobalBuildStatsXStreamConverter.java:159)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:74)
Caused: com.thoughtworks.xstream.converters.ConversionException:
---- Debugging information ----
cause-exception : java.lang.NullPointerException
cause-message : null
class : hudson.plugins.global_build_stats.GlobalBuildStatsPlugin
required-type : hudson.plugins.global_build_stats.GlobalBuildStatsPlugin
converter-type : hudson.plugins.global_build_stats.xstream.GlobalBuildStatsXStreamConverter
path : /hudson.plugins.global_build_stats.GlobalBuildStatsPlugin
line number : 2
version : not available
-------------------------------
at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:81)
at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:72)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:68)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:52)
at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:136)
at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32)
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1421)
at hudson.util.XStream2.unmarshal(XStream2.java:190)
at hudson.util.XStream2.unmarshal(XStream2.java:161)
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1399)
at hudson.XmlFile.unmarshal(XmlFile.java:196)
{}Caused: java.io.IOException: Unable to read /hdd2/jenkins/global-build-stats.xml{}
at hudson.XmlFile.unmarshal(XmlFile.java:199)
at hudson.XmlFile.unmarshal(XmlFile.java:179)
at hudson.Plugin.load(Plugin.java:271)
at hudson.plugins.global_build_stats.GlobalBuildStatsPlugin.load(GlobalBuildStatsPlugin.java:102)
at hudson.plugins.global_build_stats.business.GlobalBuildStatsPluginSaver.reloadPlugin(GlobalBuildStatsPluginSaver.java:99)
at hudson.plugins.global_build_stats.business.GlobalBuildStatsBusiness.reloadPlugin(GlobalBuildStatsBusiness.java:395)
at hudson.plugins.global_build_stats.GlobalBuildStatsPlugin$GlobalBuildStatsItemListener.onLoaded(GlobalBuildStatsPlugin.java:157)
at jenkins.model.Jenkins.<init>(Jenkins.java:1034)
at hudson.model.Hudson.<init>(Hudson.java:86)
at hudson.model.Hudson.<init>(Hudson.java:82)
at hudson.WebAppMain$3.run(WebAppMain.java:247)
We are confused why 'Jobs' folder making Jenkins service stuck. Have you ever come across with this kind of problem or do you have any idea how we can debug what is causing the problem in Jobs folder.