Recently we have added second Windows agent to our Windows master and immediately started to observe this issue. No such problems on the first Windows agent that is running here for months. This is sanitized log fragment from the agent:
mar 31, 2020 10:00:57 PM org.jvnet.winp.Native loadByUrl
WARNING: Failed to load DLL from static location
java.lang.UnsatisfiedLinkError: Native Library J:\Jenkins\remoting\jarCache\44\winp.x64.BFFE30B3B50581290B1866EF8D48C609.dll already loaded in another classloader
at java.lang.ClassLoader.loadLibrary0(Unknown Source)
at java.lang.ClassLoader.loadLibrary(Unknown Source)
at java.lang.Runtime.load0(Unknown Source)
at java.lang.System.load(Unknown Source)
at org.jvnet.winp.Native.loadDll(Native.java:242)
at org.jvnet.winp.Native.loadByUrl(Native.java:162)
at org.jvnet.winp.Native.load(Native.java:124)
at org.jvnet.winp.Native.<clinit>(Native.java:93)
at org.jvnet.winp.WinProcess.enableDebugPrivilege(WinProcess.java:245)
at hudson.util.ProcessTree$Windows.<clinit>(ProcessTree.java:701)
at hudson.util.ProcessTree.get(ProcessTree.java:447)
at hudson.Launcher$RemoteLauncher$KillTask.call(Launcher.java:1100)
at hudson.Launcher$RemoteLauncher$KillTask.call(Launcher.java:1091)
at hudson.remoting.UserRequest.perform(UserRequest.java:211)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:97)
at java.lang.Thread.run(Unknown Source)
kwi 01, 2020 12:25:05 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Terminated
kwi 01, 2020 12:25:05 AM hudson.Launcher$RemoteLaunchCallable$1 join
INFO: Failed to synchronize IO streams on the channel hudson.remoting.Channel@1aa3bc97:JNLP4-connect connection to jenkins.<mycompany.domain>/<master IPaddress>:6666
hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@1aa3bc97:JNLP4-connect connection to jenkins.<mycompany.domain>/<master IPaddress>:6666": Remote call on JNLP4-connect connection to jenkins.<mycompany.domain>/<master IPaddress>:6666 failed. The channel is closing down or has closed down
at hudson.remoting.Channel.call(Channel.java:948)
at hudson.remoting.Channel.syncIO(Channel.java:1683)
at hudson.Launcher$RemoteLaunchCallable$1.join(Launcher.java:1328)
at sun.reflect.GeneratedMethodAccessor49.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.perform(RemoteInvocationHandler.java:929)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:903)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:855)
at hudson.remoting.UserRequest.perform(UserRequest.java:211)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:97)
at java.lang.Thread.run(Unknown Source)
Caused by: java.nio.channels.ClosedChannelException
at org.jenkinsci.remoting.protocol.NetworkLayer.onRecvClosed(NetworkLayer.java:154)
at org.jenkinsci.remoting.protocol.impl.BIONetworkLayer.access$1800(BIONetworkLayer.java:48)
at org.jenkinsci.remoting.protocol.impl.BIONetworkLayer$Reader.run(BIONetworkLayer.java:264)
... 4 more
kwi 01, 2020 12:25:05 AM hudson.remoting.UserRequest perform
WARNING: LinkageError while performing UserRequest:UserRPCRequest:hudson.Launcher$RemoteProcess.join[](26)
java.lang.NoClassDefFoundError: hudson/util/ProcessTree$OSProcess$CheckVetoes
at hudson.util.ProcessTree$OSProcess.getVeto(ProcessTree.java:293)
at hudson.util.ProcessTree$WindowsOSProcess.killRecursively(ProcessTree.java:539)
at hudson.util.ProcessTree.killAll(ProcessTree.java:182)
at hudson.Proc$LocalProc.destroy(Proc.java:387)
at hudson.Proc$LocalProc.join(Proc.java:360)
at hudson.Launcher$RemoteLaunchCallable$1.join(Launcher.java:1321)
at sun.reflect.GeneratedMethodAccessor49.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.perform(RemoteInvocationHandler.java:929)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:903)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:855)
at hudson.remoting.UserRequest.perform(UserRequest.java:211)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:97)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.ClassNotFoundException: hudson.util.ProcessTree$OSProcess$CheckVetoes
at java.net.URLClassLoader.findClass(Unknown Source)
at hudson.remoting.RemoteClassLoader.findClass(RemoteClassLoader.java:171)
at java.lang.ClassLoader.loadClass(Unknown Source)
at java.lang.ClassLoader.loadClass(Unknown Source)
... 21 more
kwi 01, 2020 12:25:05 AM hudson.remoting.Request$2 run
INFO: Failed to send back a reply to the request hudson.remoting.Request$2@2808c082: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@1aa3bc97:JNLP4-connect connection to jenkins.<mycompany.domain>/<master IPaddress>:6666": channel is already closed
kwi 01, 2020 12:25:15 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Performing onReconnect operation.
kwi 01, 2020 12:25:15 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: onReconnect operation completed.
kwi 01, 2020 12:25:15 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Locating server among [http://jenkins.<mycompany.domain>:8080/]
kwi 01, 2020 12:25:19 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver resolve
INFO: Remoting server accepts the following protocols: [JNLP4-connect, Ping]
kwi 01, 2020 12:25:19 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Agent discovery successful
Agent address: jenkins.<mycompany.domain>
Agent port: 6666
Identity: d4:13:d5:<cut>:31:96:c6
kwi 01, 2020 12:25:19 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Handshaking
kwi 01, 2020 12:25:19 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connecting to jenkins.<mycompany.domain>:6666
kwi 01, 2020 12:25:19 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Trying protocol: JNLP4-connect
kwi 01, 2020 12:25:19 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Remote identity confirmed: d4:13:d5:<cut>:31:96:c6
kwi 01, 2020 12:25:19 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connected
...
kwi 01, 2020 8:03:28 AM org.jvnet.winp.Native loadByUrl
WARNING: Failed to load DLL from static location
java.lang.UnsatisfiedLinkError: Native Library J:\Jenkins\remoting\jarCache\44\winp.x64.BFFE30B3B50581290B1866EF8D48C609.dll already loaded in another classloader
at java.lang.ClassLoader.loadLibrary0(Unknown Source)
at java.lang.ClassLoader.loadLibrary(Unknown Source)
at java.lang.Runtime.load0(Unknown Source)
at java.lang.System.load(Unknown Source)
at org.jvnet.winp.Native.loadDll(Native.java:242)
at org.jvnet.winp.Native.loadByUrl(Native.java:162)
at org.jvnet.winp.Native.load(Native.java:124)
at org.jvnet.winp.Native.<clinit>(Native.java:93)
at org.jvnet.winp.WinProcess.enableDebugPrivilege(WinProcess.java:245)
at hudson.util.ProcessTree$Windows.<clinit>(ProcessTree.java:701)
at hudson.util.ProcessTree.get(ProcessTree.java:447)
at hudson.Launcher$RemoteLauncher$KillTask.call(Launcher.java:1100)
at hudson.Launcher$RemoteLauncher$KillTask.call(Launcher.java:1091)
at hudson.remoting.UserRequest.perform(UserRequest.java:211)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:97)
at java.lang.Thread.run(Unknown Source)
kwi 01, 2020 9:38:14 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Terminated
kwi 01, 2020 9:38:14 AM hudson.Launcher$RemoteLaunchCallable$1 join
INFO: Failed to synchronize IO streams on the channel hudson.remoting.Channel@b76eafc:JNLP4-connect connection to jenkins.<mycompany.domain>/<master IPaddress>:6666
hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@b76eafc:JNLP4-connect connection to jenkins.<mycompany.domain>/<master IPaddress>:6666": Remote call on JNLP4-connect connection to jenkins.<mycompany.domain>/<master IPaddress>:6666 failed. The channel is closing down or has closed down
at hudson.remoting.Channel.call(Channel.java:948)
at hudson.remoting.Channel.syncIO(Channel.java:1683)
at hudson.Launcher$RemoteLaunchCallable$1.join(Launcher.java:1328)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.perform(RemoteInvocationHandler.java:929)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:903)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:855)
at hudson.remoting.UserRequest.perform(UserRequest.java:211)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:97)
at java.lang.Thread.run(Unknown Source)
Caused by: java.nio.channels.ClosedChannelException
at org.jenkinsci.remoting.protocol.NetworkLayer.onRecvClosed(NetworkLayer.java:154)
at org.jenkinsci.remoting.protocol.impl.BIONetworkLayer.access$1800(BIONetworkLayer.java:48)
at org.jenkinsci.remoting.protocol.impl.BIONetworkLayer$Reader.run(BIONetworkLayer.java:264)
... 4 more
kwi 01, 2020 9:38:14 AM hudson.remoting.UserRequest perform
WARNING: LinkageError while performing UserRequest:UserRPCRequest:hudson.Launcher$RemoteProcess.join[](18)
java.lang.NoClassDefFoundError: hudson/util/ProcessTree$OSProcess$CheckVetoes
at hudson.util.ProcessTree$OSProcess.getVeto(ProcessTree.java:293)
at hudson.util.ProcessTree$WindowsOSProcess.killRecursively(ProcessTree.java:539)
at hudson.util.ProcessTree.killAll(ProcessTree.java:182)
at hudson.Proc$LocalProc.destroy(Proc.java:387)
at hudson.Proc$LocalProc.join(Proc.java:360)
at hudson.Launcher$RemoteLaunchCallable$1.join(Launcher.java:1321)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.perform(RemoteInvocationHandler.java:929)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:903)
at hudson.remoting.RemoteInvocationHandler$RPCRequest.call(RemoteInvocationHandler.java:855)
at hudson.remoting.UserRequest.perform(UserRequest.java:211)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:97)
at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.ClassNotFoundException: hudson.util.ProcessTree$OSProcess$CheckVetoes
at java.net.URLClassLoader.findClass(Unknown Source)
at hudson.remoting.RemoteClassLoader.findClass(RemoteClassLoader.java:171)
at java.lang.ClassLoader.loadClass(Unknown Source)
at java.lang.ClassLoader.loadClass(Unknown Source)
... 22 more
kwi 01, 2020 9:38:14 AM hudson.remoting.Request$2 run
INFO: Failed to send back a reply to the request hudson.remoting.Request$2@13fbdfb5: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@b76eafc:JNLP4-connect connection to jenkins.<mycompany.domain>/<master IPaddress>:6666": channel is already closed
kwi 01, 2020 9:38:24 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Performing onReconnect operation.
kwi 01, 2020 9:38:24 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: onReconnect operation completed.
kwi 01, 2020 9:38:24 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Locating server among [http://jenkins.<mycompany.domain>:8080/]
kwi 01, 2020 9:38:24 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver resolve
INFO: Remoting server accepts the following protocols: [JNLP4-connect, Ping]
kwi 01, 2020 9:38:24 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Agent discovery successful
Agent address: jenkins.<mycompany.domain>
Agent port: 6666
Identity: d4:13:d5:<cut>:31:96:c6
kwi 01, 2020 9:38:24 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Handshaking
kwi 01, 2020 9:38:24 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connecting to jenkins.<mycompany.domain>:6666
kwi 01, 2020 9:38:24 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Trying protocol: JNLP4-connect
kwi 01, 2020 9:38:25 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Remote identity confirmed: d4:13:d5:<cut>:31:96:c6
kwi 01, 2020 9:38:25 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connected
kwi 01, 2020 9:52:25 AM org.jenkinsci.remoting.util.AnonymousClassWarnings warn
WARNING: Attempt to (de-)serialize anonymous class hudson.FilePath$2; see: [https://jenkins.io/redirect/serialization-of-anonymous-classes/]
Failed to load native POSIX impl; falling back on Java impl. Unsupported OS.
kwi 01, 2020 10:00:41 AM hudson.plugins.tmpcleaner.TmpCleanTask delete
INFO: Deletion failed: C:\Users\jenkins\AppData\Local\Temp\tmpclean6250731123151792916.tmp
kwi 01, 2020 10:00:41 AM hudson.plugins.tmpcleaner.TmpCleanTask call
INFO: Temporary directory cleanup fried 0 B disk space, available 145,52 GB
First it happened when the agent was running as a Windows Service so without inspecting the logs I thought it must be some incopatibility issues since I auto-upgraded the master to Jenkins ver. 2.222.1 in the meantime (however no such issues on the other Windows Agent). I started the agent by a command-line and it was connected fine for several days doing the builds. Then we have fixed failing builds (our bad) and now the problem of disconnections returned, or just got more urgent since now we build more often and the agent reconnects after a failure. Maybe it's worth to note that our single build takes from 3 hours up to 7 days since we are working on a huge Unreal Engine project. I have review related issues (JENKINS-20913 and JENKINS-18578) but this seems to not be the case. Not sure how to reopen this issue but I think it should be. |