Error upgrading from 2.121.3 to 2.138.4... jenkins bricked

54 views

Skip to first unread message

Marc Esher

unread,

Mar 16, 2019, 3:41:54 PM3/16/19

to Jenkins Users

Greetings,

I have an existing Jenkins 2.121.3 LTS installation. It's been around for a long time, has a bunch of plugins, jobs, and users... typical I suppose

I tried upgrading from 2.121.3 to the latest LTS and got a bunch of errors that bricked Jenkins. I then tried again and again, and learned that I can successfully upgrade to 2.138.3, but it starts to fail at 2.138.4. I even tried upgrading to 2.138.3, and then to 2.138.4, but it fails with the same errors.

It seems to start with errors related to user migration, and then it just cascades from there. It appears filesystem related, though it's completely inexplicable to me.

I should say from the start that I'm doing this inside a docker container on docker-for-mac (for testing purposes). Since it's failing in my Docker setup I haven't yet tried this upgrade cycle on our actual Jenkins servers. I am not sure if there is a meaningful enough difference here to cause the errors I'm seeing.

I've put the entire log file at https://gist.github.com/marcesher/1b3fe905b1a74beea4c842a091555076

Here's the highlight reel:

1) a sample error for the user migration:

Mar 16, 2019 7:32:00 PM hudson.model.UserIdMigrator migrateUsers
INFO: Migrating user 'cfpb_admin' from 'users/cfpb_admin/' to 'users/cfpbadmin_6101488143392184575/'
Mar 16, 2019 7:32:00 PM hudson.model.UserIdMapper load
SEVERE: Error migrating users.
java.nio.file.DirectoryNotEmptyException: /var/lib/jenkins/users/cfpb_admin
        at sun.nio.fs.UnixCopyFile.move(UnixCopyFile.java:498)
        at sun.nio.fs.UnixFileSystemProvider.move(UnixFileSystemProvider.java:262)
        at java.nio.file.Files.move(Files.java:1395)
        at hudson.model.UserIdMigrator.migrateUsers(UserIdMigrator.java:98)
        at hudson.model.UserIdMapper.load(UserIdMapper.java:184)
        at hudson.model.UserIdMapper.init(UserIdMapper.java:75)
        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)

Mar 16, 2019 7:32:00 PM jenkins.InitReactorRunner$1 onTaskFailed
SEVERE: Failed UserIdMapper.init
java.lang.Error: java.lang.reflect.InvocationTargetException
        at hudson.init.TaskMethodFinder.invoke(TaskMethodFinder.java:110)
        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)
Caused by: 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:104)
        ... 8 more
Caused by: java.nio.file.DirectoryNotEmptyException: /var/lib/jenkins/users/cfpb_admin
        at sun.nio.fs.UnixCopyFile.move(UnixCopyFile.java:498)
        at sun.nio.fs.UnixFileSystemProvider.move(UnixFileSystemProvider.java:262)
        at java.nio.file.Files.move(Files.java:1395)
        at hudson.model.UserIdMigrator.migrateUsers(UserIdMigrator.java:98)
        at hudson.model.UserIdMapper.load(UserIdMapper.java:184)
        at hudson.model.UserIdMapper.init(UserIdMapper.java:75)
        ... 13 more

And a sample of a typical error I see subsequent to that:

INFO: Stopping Jenkins
Mar 16, 2019 7:32:00 PM hudson.model.UpdateCenter load
WARNING: Failed to load /var/lib/jenkins/hudson.model.UpdateCenter.xml
java.io.IOException: Unable to read /var/lib/jenkins/hudson.model.UpdateCenter.xml
        at hudson.XmlFile.unmarshal(XmlFile.java:181)
        at hudson.XmlFile.unmarshal(XmlFile.java:161)
        at hudson.model.UpdateCenter.load(UpdateCenter.java:852)
        at hudson.model.UpdateCenter.init(UpdateCenter.java:2288)
        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)
Caused by: com.thoughtworks.xstream.io.StreamException:  : null
        at com.thoughtworks.xstream.io.xml.AbstractXppDriver.createReader(AbstractXppDriver.java:69)
        at hudson.XmlFile.unmarshal(XmlFile.java:178)
        ... 16 more
Caused by: java.nio.channels.ClosedByInterruptException
        at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
        at sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:164)
        at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:65)
        at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:109)
        at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        at java.io.FilterInputStream.read(FilterInputStream.java:83)
        at java.io.PushbackInputStream.read(PushbackInputStream.java:139)
        at com.thoughtworks.xstream.core.util.XmlHeaderAwareReader.getHeader(XmlHeaderAwareReader.java:79)
        at com.thoughtworks.xstream.core.util.XmlHeaderAwareReader.<init>(XmlHeaderAwareReader.java:61)
        at com.thoughtworks.xstream.io.xml.AbstractXppDriver.createReader(AbstractXppDriver.java:65)
        ... 17 more

Mar 16, 2019 7:32:00 PM hudson.model.UpdateCenter save
WARNING: Failed to save /var/lib/jenkins/hudson.model.UpdateCenter.xml
java.nio.channels.ClosedByInterruptException
        at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
        at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:216)
        at hudson.util.FileChannelWriter.write(FileChannelWriter.java:72)
        at java.io.Writer.write(Writer.java:192)
        at hudson.util.AtomicFileWriter.write(AtomicFileWriter.java:162)
        at java.io.Writer.write(Writer.java:157)
        at hudson.XmlFile.write(XmlFile.java:189)
        at hudson.model.UpdateCenter.save(UpdateCenter.java:838)
        at hudson.util.PersistedList.onModified(PersistedList.java:173)
        at hudson.util.PersistedList._onModified(PersistedList.java:181)
        at hudson.util.PersistedList.add(PersistedList.java:72)
        at hudson.model.UpdateCenter.load(UpdateCenter.java:866)
        at hudson.model.UpdateCenter.init(UpdateCenter.java:2288)
        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)

Mar 16, 2019 7:32:00 PM jenkins.security.s2m.AdminWhitelistRule placeDefaultRule
WARNING: Failed to generate /var/lib/jenkins/secrets/whitelisted-callables.d/default.conf
java.nio.channels.ClosedByInterruptException
        at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
        at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:216)
        at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
        at java.nio.channels.Channels.writeFully(Channels.java:101)
        at java.nio.channels.Channels.access$000(Channels.java:61)
        at java.nio.channels.Channels$1.write(Channels.java:174)
        at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1793)
        at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1769)
        at org.apache.commons.io.IOUtils.copy(IOUtils.java:1744)
        at hudson.FilePath.copyFrom(FilePath.java:988)
        at jenkins.security.s2m.AdminWhitelistRule.placeDefaultRule(AdminWhitelistRule.java:130)
        at jenkins.security.s2m.AdminWhitelistRule.<init>(AdminWhitelistRule.java:68)
        at jenkins.security.s2m.AdminWhitelistRule$$FastClassByGuice$$5cdd1ea.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.construct(ConstructorInjector.java:85)
        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:432)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:41)
        at com.google.inject.internal.SingleFieldInjector.inject(SingleFieldInjector.java:54)
        at com.google.inject.internal.MembersInjectorImpl.injectMembers(MembersInjectorImpl.java:132)
        at com.google.inject.internal.ConstructorInjector.provision(ConstructorInjector.java:114)
        at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:85)
        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:432)
        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:394)
        at hudson.ExtensionFinder$GuiceFinder.find(ExtensionFinder.java:385)
        at hudson.ClassicPluginStrategy.findComponents(ClassicPluginStrategy.java:493)
        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 org.jenkinsci.plugins.xunit.AliasInitializer.init(AliasInitializer.java:46)
        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)

Any help is, obviously, most appreciated. Thank you!

Denis

unread,

Mar 17, 2019, 9:59:38 AM3/17/19

to Marc Esher, Jenkins Users

The LTS migration guide mentions an issue regarding user migration.

https://jenkins.io/doc/upgrade-guide/2.138/

Maybe they have a way to solve your issue

--
Sent from my Android device with K-9 Mail. Please excuse my brevity.

Jeff Thompson

unread,

Mar 19, 2019, 2:00:58 PM3/19/19

to jenkins...@googlegroups.com

That’s a very weird situation. We haven’t heard of anything like that before.

As you note, Marc, it seems to be filesystem related, though I’m also at a loss for explanations. It looks like it is failing with filesystem errors all over the place. One is related to the the userid migration from the security advisory / release. But there are many others that have nothing to do with it. It’s hard to see how the first failure caused the others, unless it somehow put the filesystem in a bad state. Which again, the filesystem should prevent.

As the advisory mentions, we recommend always taking a backup before performing an upgrade and certainly for this upgrade. It looks like you’re trying it out on a copy anyway, so that shouldn’t be an immediate problem. I doubt that the mechanism to patch a failed migration will do you any good in this case.

There is a way to manually perform the migration or at least part of it. It can be tedious and I’m not sure how useful it would be. It could allow you to get beyond the migration to try and isolate or identify the problem.

About how many users does your installation have?

Can you try this same upgrade exercise on a different test environment with a different filesystem type? That might help diagnosis or help you find an environment that works.

Jeff Thompson

--
You received this message because you are subscribed to the Google Groups "Jenkins Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to jenkinsci-use...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-users/AB41F66B-3E35-4CDC-BAEB-EFEC9CF9090C%40gmail.com.
For more options, visit https://groups.google.com/d/optout.

Marc Esher

unread,

Mar 22, 2019, 8:45:49 PM3/22/19

to Jenkins Users

Hi all, thanks for the advice. Apologies for not posting back to the group earlier with my resolution.

It turns out, I am nearly certain this is a problem with running the upgrade on Docker. This is docker-for-mac.

I found several other instances in non-Jenkins software of Java errorring due to NIO UnixCopyFile.move(), on docker. https://github.com/elastic/elasticsearch/issues/24231 and https://github.com/tuub/kitodo-mediaserver/issues/108 are examples.

When I ran the upgrade on one of our jenkins test servers -- these are ec2 linux instances, no docker in play -- from 2.121.3 to the latest LTS version, the upgrade and User migration happened as expected.

Best,

Marc

Jeff Thompson

unread,

Mar 25, 2019, 6:06:40 PM3/25/19

to jenkins...@googlegroups.com

I’m glad you were able to figure something out and move forward. It does appear to be the same issue in those reports in those other projects. In the elasticsearch one they identified it as a bug in the interaction between aufs and the JDK. As we suspected earlier it seems to involve a filesystem issue and not be related specifically to the userid migration. I wonder if the bug exists in more current versions of Java.

Jeff Thompson

--
You received this message because you are subscribed to the Google Groups "Jenkins Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to jenkinsci-use...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-users/f25f759c-5a90-4040-9490-3df2b591e96f%40googlegroups.com.

Reply all

Reply to author

Forward

0 new messages