-
Notifications
You must be signed in to change notification settings - Fork 89
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Jenkins agent pods with Error
status not removed automatically
#138
Comments
@JohnNiang: The label(s) In response to this:
Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. |
/cc @kubesphere/sig-devops |
Are there any clues that we can find? For example, the event, log output. Generally speaking, the responsibility of destroying pods belongs to Kubernetes. |
And jnlp container log as following: JNLP Log
Warning: JnlpProtocol3 is disabled by default, use JNLP_PROTOCOL_OPTS to alter the behavior
Warning: SECRET is defined twice in command-line arguments and the environment variable
Warning: AGENT_NAME is defined twice in command-line arguments and the environment variable
May 26, 2021 2:20:20 PM hudson.remoting.jnlp.Main createEngine
INFO: Setting up agent: base-4qhr6
May 26, 2021 2:20:20 PM hudson.remoting.jnlp.Main$CuiListener <init>
INFO: Jenkins agent is running in headless mode.
May 26, 2021 2:20:20 PM hudson.remoting.Engine startEngine
INFO: Using Remoting version: 3.27
Both error and output logs will be printed to /home/jenkins/agent/remoting
May 26, 2021 2:20:20 PM org.jenkinsci.remoting.engine.WorkDirManager initializeWorkDir
INFO: Using /home/jenkins/agent/remoting as a remoting work directory
May 26, 2021 2:20:21 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Locating server among [http://ks-jenkins.kubesphere-devops-system:80/]
May 26, 2021 2:20:21 PM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver resolve
INFO: Remoting server accepts the following protocols: [JNLP4-connect, Ping]
May 26, 2021 2:20:21 PM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver resolve
INFO: Remoting TCP connection tunneling is enabled. Skipping the TCP Agent Listener Port availability check
May 26, 2021 2:20:21 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Agent discovery successful
Agent address: ks-jenkins-agent.kubesphere-devops-system
Agent port: 50000
Identity: ad:4c:51:76:be:1c:76:47:b1:d1:0f:2e:b1:c9:c0:82
May 26, 2021 2:20:21 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Handshaking
May 26, 2021 2:20:21 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connecting to ks-jenkins-agent.kubesphere-devops-system:50000
May 26, 2021 2:20:21 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Trying protocol: JNLP4-connect
May 26, 2021 2:20:21 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Remote identity confirmed: ad:4c:51:76:be:1c:76:47:b1:d1:0f:2e:b1:c9:c0:82
May 26, 2021 2:20:24 PM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connected
May 27, 2021 2:39:53 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Terminated
May 27, 2021 2:40:03 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady
INFO: Failed to connect to the master. Will try again: java.net.ConnectException Connection refused (Connection refused)
May 27, 2021 2:40:13 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady
INFO: Failed to connect to the master. Will try again: java.net.ConnectException Connection refused (Connection refused)
May 27, 2021 2:40:23 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady
INFO: Failed to connect to the master. Will try again: java.net.ConnectException Connection refused (Connection refused)
May 27, 2021 2:40:33 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady
INFO: Failed to connect to the master. Will try again: java.net.ConnectException Connection refused (Connection refused)
May 27, 2021 2:40:43 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady
INFO: Failed to connect to the master. Will try again: java.net.ConnectException Connection refused (Connection refused)
May 27, 2021 2:40:53 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady
INFO: Failed to connect to the master. Will try again: java.net.ConnectException Connection refused (Connection refused)
May 27, 2021 2:41:03 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady
INFO: Failed to connect to the master. Will try again: java.net.ConnectException Connection refused (Connection refused)
May 27, 2021 2:41:13 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver waitForReady
INFO: Failed to connect to the master. Will try again: java.net.ConnectException Connection refused (Connection refused)
May 27, 2021 2:41:23 AM jenkins.slaves.restarter.JnlpSlaveRestarterInstaller$FindEffectiveRestarters$1 onReconnect
INFO: Restarting agent via jenkins.slaves.restarter.UnixSlaveRestarter@3f89e087
May 27, 2021 2:41:27 AM hudson.remoting.jnlp.Main createEngine
INFO: Setting up agent: base-4qhr6
May 27, 2021 2:41:27 AM hudson.remoting.jnlp.Main$CuiListener <init>
INFO: Jenkins agent is running in headless mode.
May 27, 2021 2:41:27 AM hudson.remoting.Engine startEngine
INFO: Using Remoting version: 3.27
Both error and output logs will be printed to /home/jenkins/agent/remoting
May 27, 2021 2:41:27 AM org.jenkinsci.remoting.engine.WorkDirManager initializeWorkDir
INFO: Using /home/jenkins/agent/remoting as a remoting work directory
May 27, 2021 2:41:28 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Locating server among [http://ks-jenkins.kubesphere-devops-system:80/]
May 27, 2021 2:41:28 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver resolve
INFO: Remoting server accepts the following protocols: [JNLP4-connect, Ping]
May 27, 2021 2:41:28 AM org.jenkinsci.remoting.engine.JnlpAgentEndpointResolver resolve
INFO: Remoting TCP connection tunneling is enabled. Skipping the TCP Agent Listener Port availability check
May 27, 2021 2:41:28 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Agent discovery successful
Agent address: ks-jenkins-agent.kubesphere-devops-system
Agent port: 50000
Identity: ad:4c:51:76:be:1c:76:47:b1:d1:0f:2e:b1:c9:c0:82
May 27, 2021 2:41:28 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Handshaking
May 27, 2021 2:41:28 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connecting to ks-jenkins-agent.kubesphere-devops-system:50000
May 27, 2021 2:41:28 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Trying protocol: JNLP4-connect
May 27, 2021 2:41:29 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Remote identity confirmed: ad:4c:51:76:be:1c:76:47:b1:d1:0f:2e:b1:c9:c0:82
May 27, 2021 2:41:29 AM org.jenkinsci.remoting.protocol.impl.ConnectionHeadersFilterLayer onRecv
INFO: [JNLP4-connect connection to ks-jenkins-agent.kubesphere-devops-system/10.233.33.237:50000] Local headers refused by remote: Unknown client name: base-4qhr6
May 27, 2021 2:41:29 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Protocol JNLP4-connect encountered an unexpected exception
java.util.concurrent.ExecutionException: org.jenkinsci.remoting.protocol.impl.ConnectionRefusalException: Unknown client name: base-4qhr6
at org.jenkinsci.remoting.util.SettableFuture.get(SettableFuture.java:223)
at hudson.remoting.Engine.innerRun(Engine.java:614)
at hudson.remoting.Engine.run(Engine.java:474)
Caused by: org.jenkinsci.remoting.protocol.impl.ConnectionRefusalException: Unknown client name: base-4qhr6
at org.jenkinsci.remoting.protocol.impl.ConnectionHeadersFilterLayer.newAbortCause(ConnectionHeadersFilterLayer.java:378)
at org.jenkinsci.remoting.protocol.impl.ConnectionHeadersFilterLayer.onRecvClosed(ConnectionHeadersFilterLayer.java:433)
at org.jenkinsci.remoting.protocol.ProtocolStack$Ptr.onRecvClosed(ProtocolStack.java:816)
at org.jenkinsci.remoting.protocol.FilterLayer.onRecvClosed(FilterLayer.java:287)
at org.jenkinsci.remoting.protocol.impl.SSLEngineFilterLayer.onRecvClosed(SSLEngineFilterLayer.java:172)
at org.jenkinsci.remoting.protocol.ProtocolStack$Ptr.onRecvClosed(ProtocolStack.java:816)
at org.jenkinsci.remoting.protocol.NetworkLayer.onRecvClosed(NetworkLayer.java:154)
at org.jenkinsci.remoting.protocol.impl.BIONetworkLayer.access$1500(BIONetworkLayer.java:48)
at org.jenkinsci.remoting.protocol.impl.BIONetworkLayer$Reader.run(BIONetworkLayer.java:247)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:93)
at java.lang.Thread.run(Thread.java:748)
Suppressed: java.nio.channels.ClosedChannelException
... 7 more
May 27, 2021 2:41:29 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Connecting to ks-jenkins-agent.kubesphere-devops-system:50000
May 27, 2021 2:41:29 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Server reports protocol JNLP4-plaintext not supported, skipping
May 27, 2021 2:41:29 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Protocol JNLP3-connect is not enabled, skipping
May 27, 2021 2:41:29 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Server reports protocol JNLP2-connect not supported, skipping
May 27, 2021 2:41:29 AM hudson.remoting.jnlp.Main$CuiListener status
INFO: Server reports protocol JNLP-connect not supported, skipping
May 27, 2021 2:41:29 AM hudson.remoting.jnlp.Main$CuiListener error
SEVERE: The server rejected the connection: None of the protocols were accepted
java.lang.Exception: The server rejected the connection: None of the protocols were accepted
at hudson.remoting.Engine.onConnectionRejected(Engine.java:675)
at hudson.remoting.Engine.innerRun(Engine.java:639)
at hudson.remoting.Engine.run(Engine.java:474) |
According to the following log output, I guess Jenkins restarted before. So, please check the pod status of
|
I've found the recurrence steps:
|
After I aborted the long running job, Jenkins appeared error as follow: Jenkins Log
2021-05-27 09:26:32.133+0000 [id=20] INFO hudson.WebAppMain$3#run: Jenkins is fully up and running
2021-05-27 09:26:42.429+0000 [id=80] INFO h.TcpSlaveAgentListener$ConnectionHandler#run: Accepted JNLP4-connect connection kubesphere/kubesphere#1 from /10.233.111.104:50116
2021-05-27 09:26:50.620+0000 [id=81] INFO o.internal.platform.Platform#log: ALPN callback dropped: HTTP/2 is disabled. Is alpn-boot on the boot class path?
2021-05-27 09:27:43.150+0000 [id=89] INFO o.c.j.p.k.KubernetesSlave#_terminate: Terminating Kubernetes instance for agent base-2ww6k
2021-05-27 09:27:43.431+0000 [id=89] INFO o.internal.platform.Platform#log: ALPN callback dropped: HTTP/2 is disabled. Is alpn-boot on the boot class path?
2021-05-27 09:27:43.635+0000 [id=89] INFO j.s.DefaultJnlpSlaveReceiver#channelClosed: Computer.threadPoolForRemoting [#10] for base-2ww6k terminated: java.nio.channels.ClosedChannelException
2021-05-27 09:27:43.730+0000 [id=96] INFO hudson.remoting.Request$2#run: Failed to send back a reply to the request hudson.remoting.Request$2@266575fe: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@62ba13fe:JNLP4-connect connection from 10.233.111.104/10.233.111.104:50116": channel is already closed
2021-05-27 09:27:43.878+0000 [id=96] INFO o.j.p.workflow.job.WorkflowRun#finish: demo-devops-projecthz2wf/always-pending-pipeline/main kubesphere/kubesphere#3 completed: ABORTED
2021-05-27 09:27:57.559+0000 [id=36] WARNING o.j.p.w.cps.CpsStepContext#completed: already completed CpsStepContext[14:sh]:Owner[demo-devops-projecthz2wf/always-pending-pipeline/main/3:demo-devops-projecthz2wf/always-pending-pipeline/main kubesphere/kubesphere#3]
java.lang.IllegalStateException: delivered here
at org.jenkinsci.plugins.workflow.cps.CpsStepContext.completed(CpsStepContext.java:339)
at org.jenkinsci.plugins.workflow.cps.CpsStepContext.onFailure(CpsStepContext.java:314)
at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.lambda$stop$3(DurableTaskStep.java:502)
at jenkins.security.ImpersonatingScheduledExecutorService$1.run(ImpersonatingScheduledExecutorService.java:58)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
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)
2021-05-27 09:27:57.561+0000 [id=36] INFO o.j.p.w.cps.CpsStepContext#completed: new failure
Also: java.lang.IllegalStateException: Not expecting pod template to be null at this point
at org.csanchez.jenkins.plugins.kubernetes.KubernetesSlave.getTemplate(KubernetesSlave.java:92)
at org.csanchez.jenkins.plugins.kubernetes.pipeline.SecretsMasker$Factory.secretsOf(SecretsMasker.java:144)
at org.csanchez.jenkins.plugins.kubernetes.pipeline.SecretsMasker$Factory.get(SecretsMasker.java:122)
at org.csanchez.jenkins.plugins.kubernetes.pipeline.SecretsMasker$Factory.get(SecretsMasker.java:94)
at org.jenkinsci.plugins.workflow.steps.DynamicContext$Typed.get(DynamicContext.java:94)
at org.jenkinsci.plugins.workflow.cps.ContextVariableSet.get(ContextVariableSet.java:139)
at org.jenkinsci.plugins.workflow.cps.CpsThread.getContextVariable(CpsThread.java:135)
at org.jenkinsci.plugins.workflow.cps.CpsStepContext.doGet(CpsStepContext.java:297)
at org.jenkinsci.plugins.workflow.support.DefaultStepContext.get(DefaultStepContext.java:75)
at org.jenkinsci.plugins.workflow.support.DefaultStepContext.getListener(DefaultStepContext.java:127)
at org.jenkinsci.plugins.workflow.support.DefaultStepContext.get(DefaultStepContext.java:87)
at org.jenkinsci.plugins.workflow.support.DefaultStepContext.makeLauncher(DefaultStepContext.java:160)
at org.jenkinsci.plugins.workflow.support.DefaultStepContext.get(DefaultStepContext.java:83)
at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.launcher(DurableTaskStep.java:484)
at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.stop(DurableTaskStep.java:513)
at org.jenkinsci.plugins.workflow.cps.CpsThread.stop(CpsThread.java:319)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$6.onSuccess(CpsFlowExecution.java:1161)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$6.onSuccess(CpsFlowExecution.java:1150)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$4$1.run(CpsFlowExecution.java:917)
at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$1.run(CpsVmExecutorService.java:38)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:136)
at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
org.jenkinsci.plugins.workflow.steps.FlowInterruptedException
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.interrupt(CpsFlowExecution.java:1147)
at org.jenkinsci.plugins.workflow.job.WorkflowRun$2.lambda$interrupt$0(WorkflowRun.java:388)
at jenkins.security.ImpersonatingScheduledExecutorService$1.run(ImpersonatingScheduledExecutorService.java:58)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
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)
2021-05-27 09:27:57.561+0000 [id=36] INFO o.j.p.w.cps.CpsStepContext#completed: previously delivered here
java.lang.Throwable
at org.jenkinsci.plugins.workflow.cps.CpsStepContext.completed(CpsStepContext.java:327)
at org.jenkinsci.plugins.workflow.cps.CpsStepContext.onFailure(CpsStepContext.java:314)
at org.jenkinsci.plugins.workflow.cps.CpsThread.stop(CpsThread.java:322)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$6.onSuccess(CpsFlowExecution.java:1161)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$6.onSuccess(CpsFlowExecution.java:1150)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$4$1.run(CpsFlowExecution.java:917)
at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$1.run(CpsVmExecutorService.java:38)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:136)
at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
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)
2021-05-27 09:27:57.562+0000 [id=36] INFO o.j.p.w.cps.CpsStepContext#completed: earlier failure
org.jenkinsci.plugins.workflow.cps.CpsStepContext$AlreadyCompleted
2021-05-27 09:27:58.944+0000 [id=172] INFO h.TcpSlaveAgentListener$ConnectionHandler#run: Accepted JNLP4-connect connection kubesphere/kubesphere#2 from /10.233.111.104:51396
2021-05-27 09:27:59.321+0000 [id=82] INFO o.j.r.p.i.ConnectionHeadersFilterLayer#onRecv: [JNLP4-connect connection from 10.233.111.104/10.233.111.104:51396] Refusing headers from remote: Unknown client name: base-2ww6k
2021-05-27 09:27:59.753+0000 [id=173] INFO h.TcpSlaveAgentListener$ConnectionHandler#run: Connection kubesphere/kubesphere#3 failed: java.io.EOFException |
In my opinion, this error caused by Jenkins Kubernetes plugin. And consider the high priority must be fixed before the next release. So, I'd suggest that we set the priority of this issue low or medium. If there's no negative feedback from @JohnNiang and others, I'm going to change it later. |
Thanks for your suggestion. I'll change priority to medium later. |
/priority medium |
/remove-priority high |
Jenkins kubernetes plugin has an similarly unresolved issue: https://issues.jenkins.io/browse/JENKINS-54683. |
I will try to wait as long as we can for the upstream repair. At the same time, I will also spend other time to inspect. |
@JohnNiang: The label(s) In response to this:
Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. |
Describe the Bug
Jenkins agent pods with
Error
status are not removed automatically. This may affect the scheduling of pod, especially the workspace with quota limit.Repruduce
See https://github.com/kubesphere/kubesphere/issues/3918#issuecomment-849486397.
Expected behavior
Jenkins agent pods with
Error
status should be removed automatically./kind bug
/area devops
/priority high
The text was updated successfully, but these errors were encountered: