[JIRA] (JENKINS-49546) java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

[stefan.drissen@gmail.com (JIRA)]

Stefan Drissen created an issue

Jenkins / JENKINS-49546 java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed Issue Type: Bug Assignee: redsolo Components: tfs-plugin Created: 2018-02-14 08:54 Environment: Windows 2012R2 x64 Java 1.8.0_161 x64 Jenkins 2.105 TFS-plugni 5.126.0 Labels: slave plugin windows Priority: Critical Reporter: Stefan Drissen Since upgrading from the pre-Java SDK TFS-plugin (3.2) to the latest plugin (5.126.0) I am needing to tickle my agents every now and then. They will work fine for a few days and then suddenly one will start throwing the above error. Once in this state, that agent never recovers and the Jenkins agent task needs to be restarted. That agent will then behave for some time. The agents are started via the Windows Task Scheduler. Complete log: Started by upstream project "<version>/build work" build number 325 originally caused by: Started by an SCM change [EnvInject] - Loading node environment variables. Building remotely on <agent> (coded_ui_oe) in workspace c:\jenkins\workspace\<version>\work\coded.ui_run.all.tests.ie FATAL: java.io.IOException: Remote call on JNLP4-connect connection from 10.2.33.142/10.2.33.142:4028 failed Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to JNLP4-connect connection from 10.2.33.142/10.2.33.142:4028 at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1696) at hudson.remoting.UserResponse.retrieve(UserRequest.java:313) at hudson.remoting.Channel.call(Channel.java:909) at hudson.plugins.tfs.model.Server.execute(Server.java:233) at hudson.plugins.tfs.model.Project.extractChangesetNumber(Project.java:280) at hudson.plugins.tfs.model.Project.getRemoteChangesetVersion(Project.java:276) at hudson.plugins.tfs.model.Project.getRemoteChangesetVersion(Project.java:292) at hudson.plugins.tfs.TeamFoundationServerScm.recordWorkspaceChangesetVersion(TeamFoundationServerScm.java:394) at hudson.plugins.tfs.TeamFoundationServerScm.checkout(TeamFoundationServerScm.java:343) at hudson.scm.SCM.checkout(SCM.java:504) at hudson.model.AbstractProject.checkout(AbstractProject.java:1203) at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574) at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86) at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499) at com.tikal.jenkins.plugins.multijob.MultiJobBuild$MultiJobRunnerImpl.run(MultiJobBuild.java:136) at hudson.model.Run.execute(Run.java:1727) at com.tikal.jenkins.plugins.multijob.MultiJobBuild.run(MultiJobBuild.java:73) at hudson.model.ResourceController.execute(ResourceController.java:97) at hudson.model.Executor.run(Executor.java:429) java.lang.NoClassDefFoundError: Could not initialize class com.microsoft.tfs.core.config.persistence.DefaultPersistenceStoreProvider at hudson.plugins.tfs.model.Server.<init>(Server.java:119) at hudson.plugins.tfs.commands.AbstractCallableCommand.createServer(AbstractCallableCommand.java:45) at hudson.plugins.tfs.commands.RemoteChangesetVersionCommand.call(RemoteChangesetVersionCommand.java:56) at hudson.plugins.tfs.commands.RemoteChangesetVersionCommand.call(RemoteChangesetVersionCommand.java:34) at hudson.remoting.UserRequest.perform(UserRequest.java:210) at hudson.remoting.UserRequest.perform(UserRequest.java:53) at hudson.remoting.Request$2.run(Request.java:358) 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$1.run(Engine.java:94) at java.lang.Thread.run(Unknown Source) Caused: java.io.IOException: Remote call on JNLP4-connect connection from 10.2.33.142/10.2.33.142:4028 failed at hudson.remoting.Channel.call(Channel.java:917) at hudson.plugins.tfs.model.Server.execute(Server.java:233) Caused: java.lang.RuntimeException at hudson.plugins.tfs.model.Server.execute(Server.java:237) at hudson.plugins.tfs.model.Project.extractChangesetNumber(Project.java:280) at hudson.plugins.tfs.model.Project.getRemoteChangesetVersion(Project.java:276) at hudson.plugins.tfs.model.Project.getRemoteChangesetVersion(Project.java:292) at hudson.plugins.tfs.TeamFoundationServerScm.recordWorkspaceChangesetVersion(TeamFoundationServerScm.java:394) at hudson.plugins.tfs.TeamFoundationServerScm.checkout(TeamFoundationServerScm.java:343) at hudson.scm.SCM.checkout(SCM.java:504) at hudson.model.AbstractProject.checkout(AbstractProject.java:1203) at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574) at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86) at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499) at com.tikal.jenkins.plugins.multijob.MultiJobBuild$MultiJobRunnerImpl.run(MultiJobBuild.java:136) at hudson.model.Run.execute(Run.java:1727) at com.tikal.jenkins.plugins.multijob.MultiJobBuild.run(MultiJobBuild.java:73) at hudson.model.ResourceController.execute(ResourceController.java:97) at hudson.model.Executor.run(Executor.java:429) Add Comment

This message was sent by Atlassian JIRA (v7.3.0#73011-sha1:3c73d0e)

[stefan.drissen@gmail.com (JIRA)]

Stefan Drissen updated an issue

Jenkins / JENKINS-49546 java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Change By: Stefan Drissen

Since upgrading from the pre-Java SDK TFS-plugin (3.2) to the latest plugin (5.126.0) I am needing to tickle my agents every now and then. They will work fine for a few days and then suddenly one will start throwing the above error. Once in this state, that agent never recovers and the Jenkins agent task needs to be restarted. That agent will then behave for some time. The agents are started via the Windows Task Scheduler. Complete log:

{code:java}

at hudson.model.Executor.run(Executor.java:429){code} Looking at the  agents agent's log, it seems to be unable to recover from a connection loss in the middle of the night: {code:java} feb 13, 2018 12:13:07 AM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 12:13:09 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryHistory', status=200, content-length=732, server-wait=1236 ms, parse=7 ms, total=1243 ms, throughput=589 B/s, gzip feb 13, 2018 12:13:09 AM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 12:13:09 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='Connect', status=200, content-length=4307, server-wait=73 ms, parse=0 ms, total=73 ms, throughput=59000 B/s, gzip feb 13, 2018 12:13:09 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryWorkspaces', status=200, content-length=15551, server-wait=20 ms, parse=2 ms, total=22 ms, throughput=706864 B/s, gzip feb 13, 2018 12:13:09 AM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 12:13:10 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryWorkspaces', status=200, content-length=16155, server-wait=58 ms, parse=2 ms, total=60 ms, throughput=269250 B/s, gzip feb 13, 2018 12:13:10 AM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 12:13:10 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='Get', status=200, content-length=410, server-wait=781 ms, parse=0 ms, total=781 ms, throughput=525 B/s, gzip feb 13, 2018 2:03:22 AM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 2:03:23 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryHistory', status=200, content-length=732, server-wait=671 ms, parse=6 ms, total=677 ms, throughput=1081 B/s, gzip feb 13, 2018 2:03:23 AM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 2:03:23 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='Connect', status=200, content-length=4307, server-wait=97 ms, parse=1 ms, total=98 ms, throughput=43949 B/s, gzip feb 13, 2018 2:03:23 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryWorkspaces', status=200, content-length=15551, server-wait=112 ms, parse=11 ms, total=123 ms, throughput=126431 B/s, gzip feb 13, 2018 2:03:23 AM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 2:03:23 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryWorkspaces', status=200, content-length=16155, server-wait=62 ms, parse=2 ms, total=64 ms, throughput=252422 B/s, gzip feb 13, 2018 2:03:23 AM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 2:03:24 AM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='Get', status=200, content-length=410, server-wait=700 ms, parse=0 ms, total=700 ms, throughput=586 B/s, gzip feb 13, 2018 9:56:28 PM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 9:56:29 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryHistory', status=200, content-length=732, server-wait=583 ms, parse=56 ms, total=639 ms, throughput=1146 B/s, gzip feb 13, 2018 9:56:29 PM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 9:56:29 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='Connect', status=200, content-length=4307, server-wait=48 ms, parse=0 ms, total=48 ms, throughput=89729 B/s, gzip feb 13, 2018 9:56:29 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryWorkspaces', status=200, content-length=15551, server-wait=21 ms, parse=2 ms, total=23 ms, throughput=676130 B/s, gzip feb 13, 2018 9:56:29 PM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 9:56:29 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryWorkspaces', status=200, content-length=16155, server-wait=61 ms, parse=1 ms, total=62 ms, throughput=260565 B/s, gzip feb 13, 2018 9:56:29 PM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 9:56:30 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='Get', status=200, content-length=410, server-wait=608 ms, parse=0 ms, total=608 ms, throughput=674 B/s, gzip feb 13, 2018 10:46:12 PM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 10:46:13 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryHistory', status=200, content-length=732, server-wait=520 ms, parse=21 ms, total=541 ms, throughput=1353 B/s, gzip feb 13, 2018 10:46:13 PM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 10:46:13 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='Connect', status=200, content-length=4307, server-wait=102 ms, parse=4 ms, total=106 ms, throughput=40632 B/s, gzip feb 13, 2018 10:46:13 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryWorkspaces', status=200, content-length=15551, server-wait=110 ms, parse=5 ms, total=115 ms, throughput=135226 B/s, gzip feb 13, 2018 10:46:13 PM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 10:46:14 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='QueryWorkspaces', status=200, content-length=16155, server-wait=62 ms, parse=2 ms, total=64 ms, throughput=252422 B/s, gzip feb 13, 2018 10:46:14 PM com.microsoft.tfs.core.config.httpclient.DefaultHTTPClientFactory logHTTPClientConfiguration INFO: HttpClient configured for https://<tfs>:8088/<collection>, authenticating as <serviceaccount> feb 13, 2018 10:46:14 PM com.microsoft.tfs.core.ws.runtime.client.SOAPService executeSOAPRequestInternal INFO: SOAP method='Get', status=200, content-length=410, server-wait=756 ms, parse=0 ms, total=756 ms, throughput=542 B/s, gzip feb 14, 2018 2:21:09 AM hudson.remoting.jnlp.Main$CuiListener status INFO: Terminated feb 14, 2018 2:21:25 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:21:40 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:21:55 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:22:10 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:22:25 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:22:40 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:22:55 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:23:10 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:23:25 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:23:40 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:23:55 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:24:10 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:24:25 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:24:40 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:24:55 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException connect timed out feb 14, 2018 2:25:06 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Master isn't ready to talk to us on http://<jenkins.master>:8080/tcpSlaveAgentListener/. Will try again: response code=503 feb 14, 2018 2:25:21 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Failed to connect to the master. Will try again: java.net.SocketTimeoutException Read timed out feb 14, 2018 2:25:31 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady INFO: Master isn't ready to talk to us on http://<jenkins.master>:8080/tcpSlaveAgentListener/. Will try again: response code=503 feb 14, 2018 2:25:42 AM hudson.remoting.jnlp.Main$CuiListener status INFO: Locating server among [http://<jenkins.master>:8080/] feb 14, 2018 2:25:42 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver resolve INFO: Remoting server accepts the following protocols: [JNLP4-connect, Ping] feb 14, 2018 2:25:42 AM hudson.remoting.jnlp.Main$CuiListener status INFO: Agent discovery successful Agent address: <jenkins.master> Agent port: 63829 Identity: 4d:a4:e7:ae:9e:f1:98:9d:6d:e2:cd:89:0b:89:ad:89 feb 14, 2018 2:25:42 AM hudson.remoting.jnlp.Main$CuiListener status INFO: Handshaking feb 14, 2018 2:25:42 AM hudson.remoting.jnlp.Main$CuiListener status INFO: Connecting to <jenkins.master>:63829 feb 14, 2018 2:25:42 AM hudson.remoting.jnlp.Main$CuiListener status INFO: Trying protocol: JNLP4-connect feb 14, 2018 2:25:42 AM hudson.remoting.jnlp.Main$CuiListener status INFO: Remote identity confirmed: 4d:a4:e7:ae:9e:f1:98:9d:6d:e2:cd:89:0b:89:ad:89 feb 14, 2018 2:25:42 AM hudson.remoting.jnlp.Main$CuiListener status INFO: Connected feb 14, 2018 2:34:11 AM hudson.remoting.UserRequest perform WARNING: LinkageError while performing UserRequest:hudson.plugins.tfs.commands.RemoteChangesetVersionCommand@28a27c23 java.lang.UnsatisfiedLinkError: com.microsoft.tfs.jni.internal.platformmisc.NativePlatformMisc.nativeGetEnvironmentVariable(Ljava/lang/String;)Ljava/lang/String; at com.microsoft.tfs.jni.internal.platformmisc.NativePlatformMisc.nativeGetEnvironmentVariable(Native Method) at com.microsoft.tfs.jni.internal.platformmisc.NativePlatformMisc.getEnvironmentVariable(NativePlatformMisc.java:121) at com.microsoft.tfs.jni.PlatformMiscUtils.getEnvironmentVariable(PlatformMiscUtils.java:47) at com.microsoft.tfs.core.persistence.VersionedVendorFilesystemPersistenceStore.makeDirectoryForVendorApplicationVersion(VersionedVendorFilesystemPersistenceStore.java:96) at com.microsoft.tfs.core.persistence.VersionedVendorFilesystemPersistenceStore.<init>(VersionedVendorFilesystemPersistenceStore.java:60) at com.microsoft.tfs.core.config.persistence.DefaultPersistenceStoreProvider.<clinit>(DefaultPersistenceStoreProvider.java:42)

at hudson.plugins.tfs.model.Server.<init>(Server.java:119) at hudson.plugins.tfs.commands.AbstractCallableCommand.createServer(AbstractCallableCommand.java:45) at hudson.plugins.tfs.commands.RemoteChangesetVersionCommand.call(RemoteChangesetVersionCommand.java:56) at hudson.plugins.tfs.commands.RemoteChangesetVersionCommand.call(RemoteChangesetVersionCommand.java:34) at hudson.remoting.UserRequest.perform(UserRequest.java:210) at hudson.remoting.UserRequest.perform(UserRequest.java:53) at hudson.remoting.Request$2.run(Request.java:358) 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$1.run(Engine.java:94) at java.lang.Thread.run(Unknown Source)

feb 14, 2018 2:34:36 AM hudson.remoting.UserRequest perform WARNING: LinkageError while performing UserRequest:hudson.plugins.tfs.commands.RemoteChangesetVersionCommand@33015a4d

java.lang.NoClassDefFoundError: Could not initialize class com.microsoft.tfs.core.config.persistence.DefaultPersistenceStoreProvider at hudson.plugins.tfs.model.Server.<init>(Server.java:119) at hudson.plugins.tfs.commands.AbstractCallableCommand.createServer(AbstractCallableCommand.java:45) at hudson.plugins.tfs.commands.RemoteChangesetVersionCommand.call(RemoteChangesetVersionCommand.java:56) at hudson.plugins.tfs.commands.RemoteChangesetVersionCommand.call(RemoteChangesetVersionCommand.java:34) at hudson.remoting.UserRequest.perform(UserRequest.java:210) at hudson.remoting.UserRequest.perform(UserRequest.java:53) at hudson.remoting.Request$2.run(Request.java:358) 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$1.run(Engine.java:94) at java.lang.Thread.run(Unknown Source)

{code}

Add Comment

[stefan.drissen@gmail.com (JIRA)]

Looking at the agents log, it seems to be unable to recover from a connection loss in the middle of the night:

[jpricket@microsoft.com (JIRA)]

Jason Prickett commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed Thanks for providing the callstack! It looks like we should probably handle this error a bit better and not let it leak out. If you are willing to try a private fix, email me at jpricket<at>microsoft.com and I will provide you with a private fix. Of course, I guess you won't know if the problem is fixed for a few days/weeks. But I would still like to have you verify the fix directly if possible. Thanks, Jason

Add Comment

[jpricket@microsoft.com (JIRA)]

Jason Prickett edited a comment on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

[~smd],

Thanks for providing the callstack! It looks like we should probably handle this error a bit better and not let it leak out. If you are willing to try a private fix, email me at jpricket<at>microsoft.com and I will provide you with a private fix. Of course, I guess you won't know if the problem is fixed for a few days/weeks. But I would still like to have you verify the fix directly if possible. Thanks, Jason

Add Comment

[stefan.drissen@gmail.com (JIRA)]

Stefan Drissen commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Hi Jason, Did you get my e-mail? I see that your e-mail and last name do not seem to match (1t vs 2t).   Kind regards,   Stefan

Add Comment

[stefan.drissen@gmail.com (JIRA)]

Stefan Drissen edited a comment on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Hi Jason, Did you get my e-mail? I see that your e-mail and last name do not seem to match (1t vs 2t). Just tried 2ts and that's immediately bounced.   Kind regards,   Stefan

Add Comment

[stefan.drissen@gmail.com (JIRA)]

Stefan Drissen commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

With the private build, the agent is now surviving death by changeset -1: Building remotely on <agent> in workspace c:\jenkins\workspace\<version>\<branch>\publish_browser-codedui Checking if there exists a mapping for c:\jenkins\workspace\<version>\<branch>\publish_browser-codedui...yes, in workspace 'Jenkins-<version>-<branch>-publish_browser-codedui-<agent>'. Downloading list of workspaces from <collection>... Getting version 'C2147483647' to 'c:\jenkins\workspace\<version>\<branch>\publish_browser-codedui'... FATAL: hudson.remoting.ProxyException: com.microsoft.tfs.core.exceptions.TECoreException: TF14019: The changeset 2147483647 does not exist. hudson.remoting.ProxyException: com.microsoft.tfs.core.ws.runtime.exceptions.SOAPFault: TF14019: The changeset 2147483647 does not exist. at com.microsoft.tfs.core.ws.runtime.client.SOAP12Service.examineResponseDOMForFault(SOAP12Service.java:117) at com.microsoft.tfs.core.ws.runtime.client.SOAPService.examineBodyForFault(SOAPService.java:987) at com.microsoft.tfs.core.ws.runtime.client.SOAPService.executeSOAPRequestInternal(SOAPService.java:665) at com.microsoft.tfs.core.ws.runtime.client.SOAPService.executeSOAPRequest(SOAPService.java:444) at ms.tfs.versioncontrol.clientservices._03._Repository5Soap12Service.get(_Repository5Soap12Service.java:109) at com.microsoft.tfs.core.clients.versioncontrol.internal.WebServiceLayer.get(WebServiceLayer.java:941) Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to JNLP4-connect connection from 10.2.34.30/10.2.34.30:55027 at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1737) at hudson.remoting.UserResponse.retrieve(UserRequest.java:313) at hudson.remoting.Channel.call(Channel.java:952) at hudson.plugins.tfs.model.Server.execute(Server.java:233) at hudson.plugins.tfs.model.Project.getFiles(Project.java:278) at hudson.plugins.tfs.actions.CheckoutAction.checkout(CheckoutAction.java:66) at hudson.plugins.tfs.TeamFoundationServerScm.checkout(TeamFoundationServerScm.java:458) at hudson.scm.SCM.checkout(SCM.java:504) at hudson.model.AbstractProject.checkout(AbstractProject.java:1203) at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574) at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86) at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499) at hudson.model.Run.execute(Run.java:1727) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43) at hudson.model.ResourceController.execute(ResourceController.java:97) at hudson.model.Executor.run(Executor.java:429) Caused: hudson.remoting.ProxyException: com.microsoft.tfs.core.exceptions.TECoreException: TF14019: The changeset 2147483647 does not exist. at com.microsoft.tfs.core.exceptions.mappers.TECoreExceptionMapper.map(TECoreExceptionMapper.java:92) at com.microsoft.tfs.core.exceptions.mappers.VersionControlExceptionMapper.map(VersionControlExceptionMapper.java:43) at com.microsoft.tfs.core.clients.versioncontrol.internal.WebServiceLayer.get(WebServiceLayer.java:980) at com.microsoft.tfs.core.clients.versioncontrol.internal.WebServiceLayerLocalworkspaces.get(WebServiceLayerLocalworkspaces.java:760) at com.microsoft.tfs.core.clients.versioncontrol.soapextensions.workspace.get(workspace.java:2434) at com.microsoft.tfs.core.clients.versioncontrol.soapextensions.workspace.get(workspace.java:2341) at com.microsoft.tfs.core.clients.versioncontrol.soapextensions.workspace.get(workspace.java:2331) at com.microsoft.tfs.core.clients.versioncontrol.soapextensions.workspace.get(workspace.java:2308) at hudson.plugins.tfs.commands.GetFilesTo<branch>FolderCommand.call(GetFilesTo<branch>FolderCommand.java:72) at hudson.plugins.tfs.commands.GetFilesTo<branch>FolderCommand.call(GetFilesTo<branch>FolderCommand.java:18) at hudson.remoting.UserRequest.perform(UserRequest.java:210) at hudson.remoting.UserRequest.perform(UserRequest.java:53) at hudson.remoting.Request$2.run(Request.java:364) at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72) at java.util.concurrent.FutureTask.run(Unknown Source) at java.util.concurrent.ThreadPoolExecutor.run<branch>er(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$<branch>er.run(Unknown Source) at hudson.remoting.Engine$1$1.run(Engine.java:94) at java.lang.Thread.run(Unknown Source) Caused: java.lang.RuntimeException at hudson.plugins.tfs.model.Server.execute(Server.java:237) at hudson.plugins.tfs.model.Project.getFiles(Project.java:278) at hudson.plugins.tfs.actions.CheckoutAction.checkout(CheckoutAction.java:66) at hudson.plugins.tfs.TeamFoundationServerScm.checkout(TeamFoundationServerScm.java:458) at hudson.scm.SCM.checkout(SCM.java:504) at hudson.model.AbstractProject.checkout(AbstractProject.java:1203) at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574) at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86) at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499) at hudson.model.Run.execute(Run.java:1727) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43) at hudson.model.ResourceController.execute(ResourceController.java:97) at hudson.model.Executor.run(Executor.java:429)

Add Comment

[brenton@letrabb.com (JIRA)]

Brantone commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Hitting this as well ... but wondering:  Does the "private fix"  actually fix it? or just further testing? the provided stacktrace looks like it's still failing, correct?

Add Comment

This message was sent by Atlassian JIRA (v7.10.1#710002-sha1:6efc396)

[stefan.drissen@gmail.com (JIRA)]

Stefan Drissen commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

@Brantone Correct, the fix only ensures that the agent does not need to be restarted, the actual issue still needs to be addressed. Kellie Jos - is at least this part of the fix going to be included in a release soon? When one gets to the point of creating shortcuts to restart all agents you know you're doing something wrong...

Add Comment

[brenton@letrabb.com (JIRA)]

Brantone commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Stefan Drissen  : curious then: with the "private fix" what actually happens when the issue is encountered? Jason Prickett : email also sent  to try out the elusive "private fix"

Add Comment

[brenton@letrabb.com (JIRA)]

Brantone commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

For what it's worth, not sure if related, but here's what spat into jenkins-slave.err.log when the job failed. Jul 05, 2018 8:38:28 PM org.jenkinsci.remoting.util.AnonymousClassWarnings warn WARNING: Attempt to (de-)serialize anonymous class org.jenkinsci.plugins.envinject.service.EnvironmentVariablesNodeLoader$1; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/ Jul 05, 2018 8:38:28 PM org.jenkinsci.remoting.util.AnonymousClassWarnings warn WARNING: Attempt to (de-)serialize anonymous class org.jenkinsci.plugins.envinject.service.EnvInjectActionSetter$1; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/ Jul 05, 2018 8:38:29 PM hudson.remoting.UserRequest perform WARNING: LinkageError while performing UserRequest:hudson.plugins.tfs.commands.RemoteChangesetVersionCommand@54f2c297 java.lang.UnsatisfiedLinkError: com.microsoft.tfs.jni.internal.platformmisc.NativePlatformMisc.nativeGetEnvironmentVariable(Ljava/lang/String;)Ljava/lang/String; at com.microsoft.tfs.jni.internal.platformmisc.NativePlatformMisc.nativeGetEnvironmentVariable(Native Method) at com.microsoft.tfs.jni.internal.platformmisc.NativePlatformMisc.getEnvironmentVariable(NativePlatformMisc.java:121) at com.microsoft.tfs.jni.PlatformMiscUtils.getEnvironmentVariable(PlatformMiscUtils.java:47) at com.microsoft.tfs.core.persistence.VersionedVendorFilesystemPersistenceStore.makeDirectoryForVendorApplicationVersion(VersionedVendorFilesystemPersistenceStore.java:96) at com.microsoft.tfs.core.persistence.VersionedVendorFilesystemPersistenceStore.<init>(VersionedVendorFilesystemPersistenceStore.java:60) at com.microsoft.tfs.core.config.persistence.DefaultPersistenceStoreProvider.<clinit>(DefaultPersistenceStoreProvider.java:42) at hudson.plugins.tfs.model.Server.<init>(Server.java:119) at hudson.plugins.tfs.commands.AbstractCallableCommand.createServer(AbstractCallableCommand.java:45) at hudson.plugins.tfs.commands.RemoteChangesetVersionCommand.call(RemoteChangesetVersionCommand.java:56) at hudson.plugins.tfs.commands.RemoteChangesetVersionCommand.call(RemoteChangesetVersionCommand.java:34) at hudson.remoting.UserRequest.perform(UserRequest.java:212) 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:93) at java.lang.Thread.run(Unknown Source) Jul 05, 2018 8:38:29 PM org.jenkinsci.remoting.util.AnonymousClassWarnings warn WARNING: Attempt to (de-)serialize anonymous class hudson.FilePath$28; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/

Add Comment

[brenton@letrabb.com (JIRA)]

Brantone edited a comment on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

For what it's worth, not sure if related, but here's what spat into jenkins-slave.err.log when the job failed.

Calling out specifically the warnings on "Attempt to (de-)serialize anonymous class" (as I know rest of the error was provided in initial ticket) {code:java}

WARNING: Attempt to (de-)serialize anonymous class hudson.FilePath$28; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/ {code}

Add Comment

[stefan.drissen@gmail.com (JIRA)]

Stefan Drissen commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Brantone - the job fails, but the agent is not left in a dead state where every subsequent job hitting that agent also fails.

Add Comment

[brenton@letrabb.com (JIRA)]

Brantone commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Gotcha!! Understood, thx.

Add Comment

[jsoref+jenkins@gmail.com (JIRA)]

Josh Soref commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Fwiw, the two warnings in are addressed by JENKINS-50457

Add Comment

[anelsen@umich.edu (JIRA)]

Andy Nelsen commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

I'm seeing this same issue in tfs-plugin v5.142.0 where the slave reports

WARNING: LinkageError while performing UserRequest:hudson.plugins.tfs.commands.RemoteChangesetVersionCommand

and then the slave-agent is toast until the Jenkins service is restarted on the agent   It seems like there was a potential "private fix" for this issue.  Was that fix ever committed and released?

Add Comment

This message was sent by Atlassian Jira (v7.11.2#711002-sha1:fdc329d)

[jason.woodgate@sicon.co.uk (JIRA)]

Jason Woodgate commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Also receiving this error, running the current latest released build (v5.139.2). Any news on a fix?

Add Comment

[gustav.moelschl@br-automation.com (JIRA)]

Gustav Moelschl commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

We had exactly the same problem with our Windows slaves. We were starting them by a Java command line using the Windows Task Scheduler and after a few days we got the errors. We solved it by configuring all Windows slaves as a Windows service. See https://wiki.jenkins.io/display/JENKINS/Step+by+step+guide+to+set+up+master+and+agent+machines+on+Windows

Add Comment

This message was sent by Atlassian Jira (v7.13.6#713006-sha1:cc4451f)

[jagjeet.chadha@nagarro.com (JIRA)]

Jagjeet Chadha commented on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Can anyone tell me how o fix the mentioned issue?

Add Comment

[jagjeet.chadha@nagarro.com (JIRA)]

Jagjeet Chadha edited a comment on JENKINS-49546

Re: java.io.IOException: Remote call on JNLP4-connect connection from <agent.ip>/<agent.ip>:4028 failed

Can anyone tell me how o fix the mentioned issue? I have started seeing the same error on Jenkins 2.213

Add Comment