jenkinsci / jenkinsci/google-compute-engine-plugin

Listener for preemption event stops working after a while

Open
#172 5 comments 0 reactions 0 assignees View on GitHub
Dominant language
Java
Stars
58
Forks
97
PR merge metrics
No merged PRs in 30d

Description

We are using preemptive nodes. We experience that Jenkins abruptly looses connection to the node when it is preempted.

We are also having a lot of messages like this:
```
Jan 09, 2020 11:19:42 AM WARNING com.google.jenkins.plugins.computeengine.ComputeEngineComputer getPreempted
Error when getting preempted status
Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to jenkins-highcpu-cihwen
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1743)
at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
at hudson.remoting.Channel.call(Channel.java:957)
at com.google.jenkins.plugins.computeengine.ComputeEngineComputer.getPreemptedStatus(ComputeEngineComputer.java:62)
at com.google.jenkins.plugins.computeengine.ComputeEngineComputer.lambda$onConnected$0(ComputeEngineComputer.java:55)
at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
java.net.SocketException: Connection reset
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:186)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
at java.base/java.io.BufferedInputStream.fill(BufferedInputStream.java:252)
at java.base/java.io.BufferedInputStream.read1(BufferedInputStream.java:292)
at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:351)
at java.base/sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:746)
at java.base/sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:689)
at java.base/sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:717)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1610)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1515)
at java.base/java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:527)
at com.google.api.client.http.javanet.NetHttpResponse.(NetHttpResponse.java:37)
at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:94)
at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:972)
at com.google.jenkins.plugins.computeengine.PreemptedCheckCallable.call(PreemptedCheckCallable.java:74)
at com.google.jenkins.plugins.computeengine.PreemptedCheckCallable.call(PreemptedCheckCallable.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.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
Caused: java.lang.RuntimeException
at com.google.jenkins.plugins.computeengine.ComputeEngineComputer.getPreemptedStatus(ComputeEngineComputer.java:71)
at com.google.jenkins.plugins.computeengine.ComputeEngineComputer.lambda$onConnected$0(ComputeEngineComputer.java:55)
at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused: java.util.concurrent.ExecutionException
at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
at com.google.jenkins.plugins.computeengine.ComputeEngineComputer.getPreempted(ComputeEngineComputer.java:102)
at com.google.jenkins.plugins.computeengine.ComputeEngineRetentionStrategy.wasPreempted(ComputeEngineRetentionStrategy.java:113)
at com.google.jenkins.plugins.computeengine.ComputeEngineRetentionStrategy.taskCompleted(ComputeEngineRetentionStrategy.java:83)
at hudson.slaves.SlaveComputer.taskCompleted(SlaveComputer.java:355)
at hudson.model.queue.WorkUnitContext.synchronizeEnd(WorkUnitContext.java:140)
at hudson.model.Executor.finish1(Executor.java:477)
at hudson.model.Executor.run(Executor.java:451)
```

They seem to be repeating every 15 minutes, and seems to be caused by the scheduled retention strategy.

Having followed the code I believe what's happening is this: Something (not sure quite what) causes the [long polling request](https://github.com/jenkinsci/google-compute-engine-plugin/blob/develop/src/main/java/com/google/jenkins/plugins/computeengine/PreemptedCheckCallable.java#L74) towards [metadata server](https://github.com/jenkinsci/google-compute-engine-plugin/blob/develop/src/main/java/com/google/jenkins/plugins/computeengine/PreemptedCheckCallable.java#L36) to die (with a connection reset).

I've tried various ways of figuring out what causes the connection to be reset without really finding anything. I've not been able to reproduce it by executing the same call with cURL either through a Jenkins job, or directly in a shell on the machine.

Whatever the cause might turn out to be, I believe this should be handled differently by Jenkins.

I would expect it to either mark the node as dying and clean up, or set up the listener again.

Contributor guide

Open the contributing guide

Research direction

Start by reading ComputeEngineComputer.onConnected/getPreemptedStatus and PreemptedCheckCallable.call, then trace how ComputeEngineRetentionStrategy handles the failed listener during task completion. Use the reported connection-reset path as the failure case; done means a preemption listener failure no longer leaves the node mishandled and the node is either cleaned up or the listener is restored.

Written by the indexing model from the issue text.

Assessment

Tech stack
google-cloud, java
Domain
cloud
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.