Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Update clean lost node without requiring a instanceId #503

Open
wants to merge 31 commits into
base: develop
Choose a base branch
from
Open

Update clean lost node without requiring a instanceId #503

wants to merge 31 commits into from

Conversation

gbhat618
Copy link
Contributor

@gbhat618 gbhat618 commented Jan 3, 2025 •
edited
Loading

Problem in existing implementation
The current CleanLostNodesWork relies on the instanceId, a unique id for each GCP cloud that is created in the Jenkins controller.
There is an issue with this unique_id based logic,

  • when a controller is created with CasC, reapplying the bundle (such as during a restart) can cause the unique id to be recomputed. Then onwards, the periodic task will ignore the instances with the previous unique id, as they might be belonging to different instances.

The logic to mark a node as lost is by checking the existence of the remote instance with the current controller.
This leads to issues in two scenarios,

  • if there are two Jenkins controllers pointing to the same GCP project, happen to have the same instanceId for the cloud,
  • or in an HA (active/active setup), one replica terminates the agent belonging to another replica.

Proposed solution
This PR proposes to use a different logic for finding a lost node, wherein, the controller will keep updating a label called jenkins_node_last_in_use with an epoch timestamp value. Any controller can delete a VM if the VM is not local to the controller and its jenkins_node_last_in_use is greater than the periodic task's 3 execution duration.

This logic overcomes both of the limitations explained above and is more robust to ensure lost VMs of any controller are deleted as long as there is at least one Jenkins controller that uses the same GCP project.

idea given by #408 (comment)

Testing done

Added new integration test using RealJenkinsRule with 2 controllers, simulating the lost node scenario and a long running pipeline scenario

integration test logs 
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT
Jan 08, 2025 2:19:43 AM com.google.jenkins.plugins.computeengine.integration.ITUtil bootDiskProject
INFO: Using boot disk project: tiger-team-testing
Jan 08, 2025 2:19:43 AM com.google.jenkins.plugins.computeengine.integration.ITUtil bootDiskImageName
INFO: Using boot disk image: projects/tiger-team-testing/global/images/jenkins-gce-integration-test-jre
=== Starting testNodeInUseWontDeleteByOtherController(com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT)
Will load plugins: RealJenkinsRuleInit.jpi antisamy-markup-formatter.jpi apache-httpcomponents-client-4-api.jpi asm-api.jpi bootstrap5-api.jpi bouncycastle-api.jpi caffeine-api.jpi commons-lang3-api.jpi commons-text-api.jpi configuration-as-code.jpi credentials.jpi display-url-api.jpi durable-task.jpi eddsa-api.jpi font-awesome-api.jpi google-compute-engine.jpl google-oauth-plugin.jpi gson-api.jpi instance-identity.jpi ionicons-api.jpi jackson2-api.jpi jakarta-activation-api.jpi jakarta-mail-api.jpi javax-activation-api.jpi jaxb.jpi jsch.jpi json-api.jpi mailer.jpi oauth-credentials.jpi plain-credentials.jpi plugin-util-api.jpi powershell.jpi prism-api.jpi scm-api.jpi script-security.jpi snakeyaml-api.jpi ssh-credentials.jpi structs.jpi trilead-api.jpi variant.jpi workflow-api.jpi workflow-basic-steps.jpi workflow-cps.jpi workflow-durable-task-step.jpi workflow-job.jpi workflow-scm-step.jpi workflow-step-api.jpi workflow-support.jpi
=== Starting testNodeInUseWontDeleteByOtherController(com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT)
Will load plugins: RealJenkinsRuleInit.jpi antisamy-markup-formatter.jpi apache-httpcomponents-client-4-api.jpi asm-api.jpi bootstrap5-api.jpi bouncycastle-api.jpi caffeine-api.jpi commons-lang3-api.jpi commons-text-api.jpi configuration-as-code.jpi credentials.jpi display-url-api.jpi durable-task.jpi eddsa-api.jpi font-awesome-api.jpi google-compute-engine.jpl google-oauth-plugin.jpi gson-api.jpi instance-identity.jpi ionicons-api.jpi jackson2-api.jpi jakarta-activation-api.jpi jakarta-mail-api.jpi javax-activation-api.jpi jaxb.jpi jsch.jpi json-api.jpi mailer.jpi oauth-credentials.jpi plain-credentials.jpi plugin-util-api.jpi powershell.jpi prism-api.jpi scm-api.jpi script-security.jpi snakeyaml-api.jpi ssh-credentials.jpi structs.jpi trilead-api.jpi variant.jpi workflow-api.jpi workflow-basic-steps.jpi workflow-cps.jpi workflow-durable-task-step.jpi workflow-job.jpi workflow-scm-step.jpi workflow-step-api.jpi workflow-support.jpi
JENKINS_HOME=/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885 SUREFIRE_FORK_NUMBER=1 /Users/gbhat/.asdf/installs/java/openjdk-17.0.2/bin/java -ea -Dhudson.Main.development=true -DRealJenkinsRule.location=file:/Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-test-harness/2129.v09f309d2339c/jenkins-test-harness-2129.v09f309d2339c.jar -DRealJenkinsRule.description=testNodeInUseWontDeleteByOtherController(com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT) -DRealJenkinsRule.token=a6e31249-9f13-44f1-b648-9b4a13fd52ce -DRealJenkinsRule.logging.com.google.jenkins.plugins.computeengine.CleanLostNodesWork=FINEST -Dwinstone.portFileName=/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/jenkins-port12698367555350140871.txt -agentlib:jdwp=transport=dt_socket,server=y,suspend=n -Dcom.google.jenkins.plugins.computeengine.CleanLostNodesWork.recurrencePeriod=60000 -jar /Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-war/2.452.3/jenkins-war-2.452.3.war --enable-future-java --httpPort=0 --httpListenAddress=127.0.0.1 --prefix=/jenkins
Listening for transport dt_socket at address: 58313
Running from: /Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-war/2.452.3/jenkins-war-2.452.3.war
webroot: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/war
2025-01-07 20:49:44.481+0000 [id=1]	INFO	winstone.Logger#logInternal: Beginning extraction from war file
2025-01-07 20:49:45.414+0000 [id=1]	INFO	org.eclipse.jetty.server.Server#doStart: jetty-10.0.20; built: 2024-01-29T20:46:45.278Z; git: 3a745c71c23682146f262b99f4ddc4c1bc41630c; jvm 17.0.2+8-86
2025-01-07 20:49:45.535+0000 [id=1]	INFO	o.e.j.w.StandardDescriptorProcessor#visitServlet: NO JSP Support for /jenkins, did not find org.eclipse.jetty.jsp.JettyJspServlet
2025-01-07 20:49:45.554+0000 [id=1]	INFO	o.e.j.s.s.DefaultSessionIdManager#doStart: Session workerName=node0
2025-01-07 20:49:45.700+0000 [id=1]	INFO	hudson.WebAppMain#contextInitialized: Jenkins home directory: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885 found at: EnvVars.masterEnvVars.get("JENKINS_HOME")
2025-01-07 20:49:45.946+0000 [id=1]	INFO	o.e.j.s.handler.ContextHandler#doStart: Started w.@7d37f1c{Jenkins v2.452.3,/jenkins,file:///Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j%20h10525679374313616885/war/,AVAILABLE}{/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/war}
2025-01-07 20:49:45.952+0000 [id=1]	INFO	o.e.j.server.AbstractConnector#doStart: Started ServerConnector@27508c5d{HTTP/1.1, (http/1.1)}{127.0.0.1:58314}
2025-01-07 20:49:45.958+0000 [id=1]	INFO	org.eclipse.jetty.server.Server#doStart: Started Server@1a72a540{STARTING}[10.0.20,sto=0] @1670ms
2025-01-07 20:49:45.960+0000 [id=31]	INFO	winstone.Logger#logInternal: Winstone Servlet Engine running: controlPort=disabled
2025-01-07 20:49:46.059+0000 [id=38]	INFO	jenkins.InitReactorRunner$1#onAttained: Started initialization
2025-01-07 20:49:46.134+0000 [id=60]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/mina-sshd-api-core.jpi
2025-01-07 20:49:46.152+0000 [id=60]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/mina-sshd-api-common.jpi
2025-01-07 20:49:46.173+0000 [id=60]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/sshd.jpi
2025-01-07 20:49:46.184+0000 [id=60]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/javax-mail-api.jpi
2025-01-07 20:49:46.788+0000 [id=41]	WARNING	hudson.ClassicPluginStrategy#createClassJarFromWebInfClasses: Created /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/powershell/WEB-INF/lib/classes.jar; update plugin to a version created with a newer harness
2025-01-07 20:49:46.801+0000 [id=41]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/matrix-auth.jpi
2025-01-07 20:49:46.825+0000 [id=41]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/echarts-api.jpi
2025-01-07 20:49:47.086+0000 [id=41]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/junit.jpi
2025-01-07 20:49:47.094+0000 [id=41]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/jquery3-api.jpi
2025-01-07 20:49:47.102+0000 [id=41]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/matrix-project.jpi
2025-01-07 20:49:47.111+0000 [id=41]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/checks-api.jpi
2025-01-07 20:49:47.118+0000 [id=41]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/command-launcher.jpi
2025-01-07 20:49:47.125+0000 [id=41]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/plugins/jdk-tool.jpi
2025-01-07 20:49:47.406+0000 [id=38]	INFO	jenkins.InitReactorRunner$1#onAttained: Listed all plugins
RealJenkinsRule ready
2025-01-07 20:49:49.016+0000 [id=56]	INFO	jenkins.InitReactorRunner$1#onAttained: Prepared all plugins
2025-01-07 20:49:49.024+0000 [id=60]	INFO	jenkins.InitReactorRunner$1#onAttained: Started all plugins
2025-01-07 20:49:49.024+0000 [id=45]	INFO	jenkins.InitReactorRunner$1#onAttained: Augmented all extensions
2025-01-07 20:49:49.412+0000 [id=54]	INFO	jenkins.InitReactorRunner$1#onAttained: System config loaded
2025-01-07 20:49:49.451+0000 [id=54]	INFO	jenkins.InitReactorRunner$1#onAttained: System config adapted
2025-01-07 20:49:49.452+0000 [id=46]	INFO	jenkins.InitReactorRunner$1#onAttained: Loaded all jobs
2025-01-07 20:49:49.456+0000 [id=52]	INFO	jenkins.InitReactorRunner$1#onAttained: Configuration for all jobs updated
2025-01-07 20:49:49.461+0000 [id=47]	INFO	jenkins.model.Jenkins#setInstallState: Install state transitioning from: null to: TEST
2025-01-07 20:49:49.519+0000 [id=41]	INFO	jenkins.InitReactorRunner$1#onAttained: Completed initialization
2025-01-07 20:49:49.538+0000 [id=29]	INFO	hudson.lifecycle.Lifecycle#onReady: Jenkins is fully up and running
Checking status
Jenkins is running at http://localhost:58314/jenkins/
2025-01-07 20:49:49.645+0000 [id=24]	INFO	c.g.j.p.c.integration.ITUtil#bootDiskProject: Using boot disk project: tiger-team-testing
2025-01-07 20:49:49.645+0000 [id=24]	INFO	c.g.j.p.c.integration.ITUtil#bootDiskImageName: Using boot disk image: projects/tiger-team-testing/global/images/jenkins-gce-integration-test-jre
JENKINS_HOME=/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044 SUREFIRE_FORK_NUMBER=1 /Users/gbhat/.asdf/installs/java/openjdk-17.0.2/bin/java -ea -Dhudson.Main.development=true -DRealJenkinsRule.location=file:/Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-test-harness/2129.v09f309d2339c/jenkins-test-harness-2129.v09f309d2339c.jar -DRealJenkinsRule.description=testNodeInUseWontDeleteByOtherController(com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT) -DRealJenkinsRule.token=fdabd90d-00da-4f63-ac48-27b997850b58 -DRealJenkinsRule.logging.com.google.jenkins.plugins.computeengine.CleanLostNodesWork=FINEST -Dwinstone.portFileName=/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/jenkins-port14891605559348544093.txt -agentlib:jdwp=transport=dt_socket,server=y,suspend=n -Dcom.google.jenkins.plugins.computeengine.CleanLostNodesWork.recurrencePeriod=60000 -jar /Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-war/2.452.3/jenkins-war-2.452.3.war --enable-future-java --httpPort=0 --httpListenAddress=127.0.0.1 --prefix=/jenkins
Listening for transport dt_socket at address: 58319
Running from: /Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-war/2.452.3/jenkins-war-2.452.3.war
webroot: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/war
2025-01-07 20:49:50.092+0000 [id=1]	INFO	winstone.Logger#logInternal: Beginning extraction from war file
2025-01-07 20:49:50.998+0000 [id=1]	INFO	org.eclipse.jetty.server.Server#doStart: jetty-10.0.20; built: 2024-01-29T20:46:45.278Z; git: 3a745c71c23682146f262b99f4ddc4c1bc41630c; jvm 17.0.2+8-86
2025-01-07 20:49:51.127+0000 [id=1]	INFO	o.e.j.w.StandardDescriptorProcessor#visitServlet: NO JSP Support for /jenkins, did not find org.eclipse.jetty.jsp.JettyJspServlet
2025-01-07 20:49:51.146+0000 [id=1]	INFO	o.e.j.s.s.DefaultSessionIdManager#doStart: Session workerName=node0
2025-01-07 20:49:51.312+0000 [id=1]	INFO	hudson.WebAppMain#contextInitialized: Jenkins home directory: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044 found at: EnvVars.masterEnvVars.get("JENKINS_HOME")
2025-01-07 20:49:51.529+0000 [id=1]	INFO	o.e.j.s.handler.ContextHandler#doStart: Started w.@7d37f1c{Jenkins v2.452.3,/jenkins,file:///Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j%20h6358856283336938044/war/,AVAILABLE}{/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/war}
2025-01-07 20:49:51.536+0000 [id=1]	INFO	o.e.j.server.AbstractConnector#doStart: Started ServerConnector@27508c5d{HTTP/1.1, (http/1.1)}{127.0.0.1:58320}
2025-01-07 20:49:51.543+0000 [id=1]	INFO	org.eclipse.jetty.server.Server#doStart: Started Server@1a72a540{STARTING}[10.0.20,sto=0] @1637ms
2025-01-07 20:49:51.544+0000 [id=31]	INFO	winstone.Logger#logInternal: Winstone Servlet Engine running: controlPort=disabled
2025-01-07 20:49:51.626+0000 [id=40]	INFO	jenkins.InitReactorRunner$1#onAttained: Started initialization
2025-01-07 20:49:51.687+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/mina-sshd-api-common.jpi
2025-01-07 20:49:51.703+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/mina-sshd-api-core.jpi
2025-01-07 20:49:51.720+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/sshd.jpi
2025-01-07 20:49:51.738+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/javax-mail-api.jpi
2025-01-07 20:49:52.299+0000 [id=53]	WARNING	hudson.ClassicPluginStrategy#createClassJarFromWebInfClasses: Created /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/powershell/WEB-INF/lib/classes.jar; update plugin to a version created with a newer harness
2025-01-07 20:49:52.312+0000 [id=53]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/matrix-auth.jpi
2025-01-07 20:49:52.339+0000 [id=53]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/echarts-api.jpi
2025-01-07 20:49:52.566+0000 [id=53]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/junit.jpi
2025-01-07 20:49:52.575+0000 [id=53]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/jquery3-api.jpi
2025-01-07 20:49:52.583+0000 [id=53]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/matrix-project.jpi
2025-01-07 20:49:52.595+0000 [id=53]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/checks-api.jpi
2025-01-07 20:49:52.602+0000 [id=53]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/command-launcher.jpi
2025-01-07 20:49:52.610+0000 [id=53]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/plugins/jdk-tool.jpi
2025-01-07 20:49:52.883+0000 [id=57]	INFO	jenkins.InitReactorRunner$1#onAttained: Listed all plugins
RealJenkinsRule ready
2025-01-07 20:49:54.795+0000 [id=42]	INFO	jenkins.InitReactorRunner$1#onAttained: Prepared all plugins
2025-01-07 20:49:54.805+0000 [id=38]	INFO	jenkins.InitReactorRunner$1#onAttained: Started all plugins
2025-01-07 20:49:54.806+0000 [id=54]	INFO	jenkins.InitReactorRunner$1#onAttained: Augmented all extensions
2025-01-07 20:49:55.390+0000 [id=56]	INFO	jenkins.InitReactorRunner$1#onAttained: System config loaded
2025-01-07 20:49:55.429+0000 [id=56]	INFO	jenkins.InitReactorRunner$1#onAttained: System config adapted
2025-01-07 20:49:55.429+0000 [id=47]	INFO	jenkins.InitReactorRunner$1#onAttained: Loaded all jobs
2025-01-07 20:49:55.435+0000 [id=53]	INFO	jenkins.InitReactorRunner$1#onAttained: Configuration for all jobs updated
2025-01-07 20:49:55.442+0000 [id=53]	INFO	jenkins.model.Jenkins#setInstallState: Install state transitioning from: null to: TEST
2025-01-07 20:49:55.501+0000 [id=59]	INFO	jenkins.InitReactorRunner$1#onAttained: Completed initialization
2025-01-07 20:49:55.518+0000 [id=29]	INFO	hudson.lifecycle.Lifecycle#onReady: Jenkins is fully up and running
Checking status
Jenkins is running at http://localhost:58320/jenkins/
2025-01-07 20:49:55.658+0000 [id=37]	INFO	c.g.j.p.c.integration.ITUtil#bootDiskProject: Using boot disk project: tiger-team-testing
2025-01-07 20:49:55.659+0000 [id=37]	INFO	c.g.j.p.c.integration.ITUtil#bootDiskImageName: Using boot disk image: projects/tiger-team-testing/global/images/jenkins-gce-integration-test-jre
[p1#1]    0.000 Started
[p1#1]    0.002 [Pipeline] Start of Pipeline
[p1#1]    0.003 [Pipeline] node
[p1#1]   14.044 Still waiting to schedule task
[p1#1]   14.046 ‘Jenkins’ doesn’t have label ‘integration’
2025-01-07 20:50:30.972+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:50:30.986+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:50:31.405+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:50:31.408+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:50:32.096+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-07 20:50:32.097+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:50:33.138+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-07 20:50:33.139+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:51:29.482+0000 [id=81]	INFO	c.g.j.p.c.ComputeEngineCloud#provision: Provisioning node from configs [com.google.jenkins.plugins.computeengine.InstanceConfiguration@66db7cce] for excess workload of 1 units of label 'integration'
2025-01-07 20:51:30.393+0000 [id=81]	INFO	c.g.j.p.c.ComputeEngineCloud#availableNodeCapacity: Found capacity for 10 nodes in cloud integration
2025-01-07 20:51:30.401+0000 [id=81]	INFO	c.g.j.p.c.InstanceConfiguration#instance: User selected to use an autogenerated ssh key pair
2025-01-07 20:51:30.973+0000 [id=80]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:51:30.975+0000 [id=80]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:51:31.402+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:51:31.406+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:51:31.759+0000 [id=80]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-07 20:51:31.759+0000 [id=80]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:51:32.386+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-07 20:51:32.386+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:51:32.722+0000 [id=81]	INFO	c.g.j.p.c.InstanceConfiguration#provision: Sent insert request for instance configuration [integration]
2025-01-07 20:51:32.740+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineComputerLauncher#launch: Launch will wait 300000 for operation operation-1736283091752-62b23e8e9d513-0b27de54-0c005daf to complete...
2025-01-07 20:51:32.754+0000 [id=81]	INFO	h.s.NodeProvisioner$StandardStrategyImpl#apply: Started provisioning integration-jgm7ny from gce-integration with 1 executors. Remaining excess workload: 0
2025-01-07 20:51:32.755+0000 [id=129]	INFO	c.g.j.p.c.ComputeEngineCloud#lambda$getPlannedNodeFuture$0: Waiting 300000ms for node integration-jgm7ny to connect
2025-01-07 20:51:54.148+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Launching instance: integration-jgm7ny
2025-01-07 20:51:54.149+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: bootstrap
2025-01-07 20:51:54.150+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Getting keypair...
2025-01-07 20:51:54.151+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Using autogenerated ssh keypair
2025-01-07 20:51:54.152+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Authenticating as jenkins
2025-01-07 20:51:55.583+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Connecting to 34.139.102.44 on port 22, with timeout 10000.
2025-01-07 20:51:56.078+0000 [id=126]	WARNING	c.g.j.p.c.ComputeEngineCloud#log: An error occured: There was a problem while connecting to 34.139.102.44:22
2025-01-07 20:52:02.394+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Connecting to 34.139.102.44 on port 22, with timeout 10000.
2025-01-07 20:52:04.272+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Connected via SSH.
2025-01-07 20:52:05.328+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Verifying: java -Dhudson.remoting.Launcher.pingIntervalSec=-1 -fullversion
2025-01-07 20:52:06.155+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Copying agent.jar to: /tmp
2025-01-07 20:52:09.423+0000 [id=126]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Launching Jenkins agent via plugin SSH: java -Dhudson.remoting.Launcher.pingIntervalSec=-1 -jar /tmp/agent.jar
2025-01-07 20:52:30.976+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:52:30.978+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:52:31.404+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:52:31.407+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:52:32.126+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:52:32.126+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 1 local instances
2025-01-07 20:52:32.843+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:52:32.843+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:52:32.870+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#isOrphaned: Instance integration-jgm7ny last_refresh label value: 2025_01_07t20_49_49_877z, isOrphan: false
2025-01-07 20:52:33.746+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#updateLocalInstancesLabel: Updated label for instance integration-jgm7ny
2025-01-07 20:52:34.615+0000 [id=129]	INFO	c.g.j.p.c.ComputeEngineCloud#lambda$getPlannedNodeFuture$0: 61861ms elapsed waiting for node integration-jgm7ny to connect
[p1#1]  159.561 Running on integration-jgm7ny in /tmp/workspace/p1
[p1#1]  159.562 [Pipeline] {
[p1#1]  159.563 [Pipeline] echo
[p1#1]  159.563 do first sleep
[p1#1]  159.563 [Pipeline] sleep
[p1#1]  166.590 Sleeping for 1 min 0 sec
2025-01-07 20:53:30.976+0000 [id=76]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:53:30.978+0000 [id=76]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:53:31.404+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:53:31.406+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:53:31.778+0000 [id=76]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:53:31.779+0000 [id=76]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 1 local instances
2025-01-07 20:53:32.863+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:53:32.864+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:53:32.865+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#isOrphaned: Instance integration-jgm7ny last_refresh label value: 2025_01_07t20_52_32_127z, isOrphan: false
2025-01-07 20:53:33.337+0000 [id=76]	FINEST	c.g.j.p.c.CleanLostNodesWork#updateLocalInstancesLabel: Updated label for instance integration-jgm7ny
[p1#1]  219.772 [Pipeline] echo
[p1#1]  219.773 first sleep done
[p1#1]  219.773 [Pipeline] sleep
[p1#1]  225.792 Sleeping for 3 min 0 sec
2025-01-07 20:54:30.976+0000 [id=78]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:54:30.979+0000 [id=78]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:54:31.404+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:54:31.409+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:54:31.754+0000 [id=78]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:54:31.754+0000 [id=78]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 1 local instances
2025-01-07 20:54:32.307+0000 [id=78]	FINEST	c.g.j.p.c.CleanLostNodesWork#updateLocalInstancesLabel: Updated label for instance integration-jgm7ny
2025-01-07 20:54:32.435+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:54:32.436+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:54:32.436+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#isOrphaned: Instance integration-jgm7ny last_refresh label value: 2025_01_07t20_53_31_779z, isOrphan: false
2025-01-07 20:55:30.982+0000 [id=34]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:55:30.986+0000 [id=34]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:55:31.410+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:55:31.414+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:55:31.810+0000 [id=34]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:55:31.811+0000 [id=34]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 1 local instances
2025-01-07 20:55:32.500+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:55:32.500+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:55:32.501+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#isOrphaned: Instance integration-jgm7ny last_refresh label value: 2025_01_07t20_54_31_755z, isOrphan: false
2025-01-07 20:55:33.409+0000 [id=34]	FINEST	c.g.j.p.c.CleanLostNodesWork#updateLocalInstancesLabel: Updated label for instance integration-jgm7ny
2025-01-07 20:56:30.993+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:56:30.996+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:56:31.424+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:56:31.426+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:56:32.149+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:56:32.150+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 1 local instances
2025-01-07 20:56:33.225+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:56:33.226+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:56:33.226+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#isOrphaned: Instance integration-jgm7ny last_refresh label value: 2025_01_07t20_55_31_811z, isOrphan: false
2025-01-07 20:56:33.711+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#updateLocalInstancesLabel: Updated label for instance integration-jgm7ny
[p1#1]  399.506 [Pipeline] echo
[p1#1]  399.508 sleep done
[p1#1]  399.508 [Pipeline] }
[p1#1]  399.508 [Pipeline] // node
[p1#1]  399.509 [Pipeline] End of Pipeline
[p1#1]  399.509 Finished: SUCCESS
2025-01-07 20:56:37.665+0000 [id=87]	INFO	c.g.j.p.c.integration.ITUtil#teardownResources: teardown
2025-01-07 20:56:38.547+0000 [id=87]	INFO	c.g.j.p.c.integration.ITUtil#deleteIntegrationInstances: Cleaning up old instances; found 1 instances to delete, it may take a while for this deletion
2025-01-07 20:56:38.549+0000 [id=87]	INFO	c.g.j.p.c.integration.ITUtil#safeDelete: deleting instance: integration-jgm7ny
2025-01-07 20:56:39.071+0000 [id=190]	INFO	hudson.lifecycle.Lifecycle#onStop: Stopping Jenkins as requested by SYSTEM
2025-01-07 20:56:39.072+0000 [id=190]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Stopping Jenkins
2025-01-07 20:56:39.438+0000 [id=190]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Jenkins stopped
2025-01-07 20:56:39.470+0000 [id=32]	INFO	winstone.Logger#logInternal: JVM is terminating. Shutting down Jetty
2025-01-07 20:56:39.471+0000 [id=32]	INFO	org.eclipse.jetty.server.Server#doStop: Stopped Server@1a72a540{STOPPING}[10.0.20,sto=0]
2025-01-07 20:56:39.473+0000 [id=32]	INFO	o.e.j.server.AbstractConnector#doStop: Stopped ServerConnector@27508c5d{HTTP/1.1, (http/1.1)}{127.0.0.1:0}
2025-01-07 20:56:39.476+0000 [id=32]	INFO	o.e.j.s.handler.ContextHandler#doStop: Stopped w.@7d37f1c{Jenkins v2.452.3,/jenkins,null,STOPPED}{/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885/war}
Jan 08, 2025 2:26:39 AM org.jvnet.hudson.test.TemporaryDirectoryAllocator dispose
INFO: deleting /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h10525679374313616885
2025-01-07 20:56:40.429+0000 [id=124]	INFO	hudson.lifecycle.Lifecycle#onStop: Stopping Jenkins as requested by SYSTEM
2025-01-07 20:56:40.430+0000 [id=124]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Stopping Jenkins
2025-01-07 20:56:40.467+0000 [id=124]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Jenkins stopped
2025-01-07 20:56:40.501+0000 [id=32]	INFO	winstone.Logger#logInternal: JVM is terminating. Shutting down Jetty
2025-01-07 20:56:40.501+0000 [id=32]	INFO	org.eclipse.jetty.server.Server#doStop: Stopped Server@1a72a540{STOPPING}[10.0.20,sto=0]
2025-01-07 20:56:40.503+0000 [id=32]	INFO	o.e.j.server.AbstractConnector#doStop: Stopped ServerConnector@27508c5d{HTTP/1.1, (http/1.1)}{127.0.0.1:0}
2025-01-07 20:56:40.505+0000 [id=32]	INFO	o.e.j.s.handler.ContextHandler#doStop: Stopped w.@7d37f1c{Jenkins v2.452.3,/jenkins,null,STOPPED}{/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044/war}
Jan 08, 2025 2:26:40 AM org.jvnet.hudson.test.TemporaryDirectoryAllocator dispose
INFO: deleting /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h6358856283336938044
=== Starting testLostNodeCleanedUpBySecondController(com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT)
Will load plugins: RealJenkinsRuleInit.jpi antisamy-markup-formatter.jpi apache-httpcomponents-client-4-api.jpi asm-api.jpi bootstrap5-api.jpi bouncycastle-api.jpi caffeine-api.jpi commons-lang3-api.jpi commons-text-api.jpi configuration-as-code.jpi credentials.jpi display-url-api.jpi durable-task.jpi eddsa-api.jpi font-awesome-api.jpi google-compute-engine.jpl google-oauth-plugin.jpi gson-api.jpi instance-identity.jpi ionicons-api.jpi jackson2-api.jpi jakarta-activation-api.jpi jakarta-mail-api.jpi javax-activation-api.jpi jaxb.jpi jsch.jpi json-api.jpi mailer.jpi oauth-credentials.jpi plain-credentials.jpi plugin-util-api.jpi powershell.jpi prism-api.jpi scm-api.jpi script-security.jpi snakeyaml-api.jpi ssh-credentials.jpi structs.jpi trilead-api.jpi variant.jpi workflow-api.jpi workflow-basic-steps.jpi workflow-cps.jpi workflow-durable-task-step.jpi workflow-job.jpi workflow-scm-step.jpi workflow-step-api.jpi workflow-support.jpi
=== Starting testLostNodeCleanedUpBySecondController(com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT)
Will load plugins: RealJenkinsRuleInit.jpi antisamy-markup-formatter.jpi apache-httpcomponents-client-4-api.jpi asm-api.jpi bootstrap5-api.jpi bouncycastle-api.jpi caffeine-api.jpi commons-lang3-api.jpi commons-text-api.jpi configuration-as-code.jpi credentials.jpi display-url-api.jpi durable-task.jpi eddsa-api.jpi font-awesome-api.jpi google-compute-engine.jpl google-oauth-plugin.jpi gson-api.jpi instance-identity.jpi ionicons-api.jpi jackson2-api.jpi jakarta-activation-api.jpi jakarta-mail-api.jpi javax-activation-api.jpi jaxb.jpi jsch.jpi json-api.jpi mailer.jpi oauth-credentials.jpi plain-credentials.jpi plugin-util-api.jpi powershell.jpi prism-api.jpi scm-api.jpi script-security.jpi snakeyaml-api.jpi ssh-credentials.jpi structs.jpi trilead-api.jpi variant.jpi workflow-api.jpi workflow-basic-steps.jpi workflow-cps.jpi workflow-durable-task-step.jpi workflow-job.jpi workflow-scm-step.jpi workflow-step-api.jpi workflow-support.jpi
JENKINS_HOME=/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723 SUREFIRE_FORK_NUMBER=1 /Users/gbhat/.asdf/installs/java/openjdk-17.0.2/bin/java -ea -Dhudson.Main.development=true -DRealJenkinsRule.location=file:/Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-test-harness/2129.v09f309d2339c/jenkins-test-harness-2129.v09f309d2339c.jar -DRealJenkinsRule.description=testLostNodeCleanedUpBySecondController(com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT) -DRealJenkinsRule.token=37a6387c-71f7-4964-aa55-3c7663ae680a -DRealJenkinsRule.logging.com.google.jenkins.plugins.computeengine.CleanLostNodesWork=FINEST -Dwinstone.portFileName=/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/jenkins-port7384312205329928239.txt -agentlib:jdwp=transport=dt_socket,server=y,suspend=n -Dcom.google.jenkins.plugins.computeengine.CleanLostNodesWork.recurrencePeriod=60000 -jar /Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-war/2.452.3/jenkins-war-2.452.3.war --enable-future-java --httpPort=0 --httpListenAddress=127.0.0.1 --prefix=/jenkins
Listening for transport dt_socket at address: 58593
Running from: /Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-war/2.452.3/jenkins-war-2.452.3.war
webroot: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/war
2025-01-07 20:56:41.674+0000 [id=1]	INFO	winstone.Logger#logInternal: Beginning extraction from war file
2025-01-07 20:56:42.441+0000 [id=1]	INFO	org.eclipse.jetty.server.Server#doStart: jetty-10.0.20; built: 2024-01-29T20:46:45.278Z; git: 3a745c71c23682146f262b99f4ddc4c1bc41630c; jvm 17.0.2+8-86
2025-01-07 20:56:42.552+0000 [id=1]	INFO	o.e.j.w.StandardDescriptorProcessor#visitServlet: NO JSP Support for /jenkins, did not find org.eclipse.jetty.jsp.JettyJspServlet
2025-01-07 20:56:42.568+0000 [id=1]	INFO	o.e.j.s.s.DefaultSessionIdManager#doStart: Session workerName=node0
2025-01-07 20:56:42.712+0000 [id=1]	INFO	hudson.WebAppMain#contextInitialized: Jenkins home directory: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723 found at: EnvVars.masterEnvVars.get("JENKINS_HOME")
2025-01-07 20:56:42.929+0000 [id=1]	INFO	o.e.j.s.handler.ContextHandler#doStart: Started w.@7d37f1c{Jenkins v2.452.3,/jenkins,file:///Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j%20h9076000789041025723/war/,AVAILABLE}{/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/war}
2025-01-07 20:56:42.934+0000 [id=1]	INFO	o.e.j.server.AbstractConnector#doStart: Started ServerConnector@27508c5d{HTTP/1.1, (http/1.1)}{127.0.0.1:58595}
2025-01-07 20:56:42.941+0000 [id=1]	INFO	org.eclipse.jetty.server.Server#doStart: Started Server@1a72a540{STARTING}[10.0.20,sto=0] @1438ms
2025-01-07 20:56:42.942+0000 [id=31]	INFO	winstone.Logger#logInternal: Winstone Servlet Engine running: controlPort=disabled
2025-01-07 20:56:43.041+0000 [id=40]	INFO	jenkins.InitReactorRunner$1#onAttained: Started initialization
2025-01-07 20:56:43.096+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/mina-sshd-api-core.jpi
2025-01-07 20:56:43.114+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/mina-sshd-api-common.jpi
2025-01-07 20:56:43.128+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/sshd.jpi
2025-01-07 20:56:43.138+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/javax-mail-api.jpi
2025-01-07 20:56:43.687+0000 [id=45]	WARNING	hudson.ClassicPluginStrategy#createClassJarFromWebInfClasses: Created /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/powershell/WEB-INF/lib/classes.jar; update plugin to a version created with a newer harness
2025-01-07 20:56:43.696+0000 [id=45]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/matrix-auth.jpi
2025-01-07 20:56:43.720+0000 [id=45]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/echarts-api.jpi
2025-01-07 20:56:44.005+0000 [id=45]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/junit.jpi
2025-01-07 20:56:44.013+0000 [id=45]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/jquery3-api.jpi
2025-01-07 20:56:44.020+0000 [id=45]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/matrix-project.jpi
2025-01-07 20:56:44.030+0000 [id=45]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/checks-api.jpi
2025-01-07 20:56:44.036+0000 [id=45]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/command-launcher.jpi
2025-01-07 20:56:44.043+0000 [id=45]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/plugins/jdk-tool.jpi
2025-01-07 20:56:44.289+0000 [id=38]	INFO	jenkins.InitReactorRunner$1#onAttained: Listed all plugins
RealJenkinsRule ready
2025-01-07 20:56:45.923+0000 [id=41]	INFO	jenkins.InitReactorRunner$1#onAttained: Prepared all plugins
2025-01-07 20:56:45.929+0000 [id=58]	INFO	jenkins.InitReactorRunner$1#onAttained: Started all plugins
2025-01-07 20:56:45.929+0000 [id=57]	INFO	jenkins.InitReactorRunner$1#onAttained: Augmented all extensions
2025-01-07 20:56:46.342+0000 [id=60]	INFO	jenkins.InitReactorRunner$1#onAttained: System config loaded
2025-01-07 20:56:46.374+0000 [id=60]	INFO	jenkins.InitReactorRunner$1#onAttained: System config adapted
2025-01-07 20:56:46.374+0000 [id=54]	INFO	jenkins.InitReactorRunner$1#onAttained: Loaded all jobs
2025-01-07 20:56:46.374+0000 [id=59]	INFO	jenkins.InitReactorRunner$1#onAttained: Configuration for all jobs updated
2025-01-07 20:56:46.383+0000 [id=41]	INFO	jenkins.model.Jenkins#setInstallState: Install state transitioning from: null to: TEST
2025-01-07 20:56:46.433+0000 [id=46]	INFO	jenkins.InitReactorRunner$1#onAttained: Completed initialization
2025-01-07 20:56:46.447+0000 [id=29]	INFO	hudson.lifecycle.Lifecycle#onReady: Jenkins is fully up and running
Checking status
Jenkins is running at http://localhost:58595/jenkins/
2025-01-07 20:56:46.558+0000 [id=37]	INFO	c.g.j.p.c.integration.ITUtil#bootDiskProject: Using boot disk project: tiger-team-testing
2025-01-07 20:56:46.558+0000 [id=37]	INFO	c.g.j.p.c.integration.ITUtil#bootDiskImageName: Using boot disk image: projects/tiger-team-testing/global/images/jenkins-gce-integration-test-jre
JENKINS_HOME=/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157 SUREFIRE_FORK_NUMBER=1 /Users/gbhat/.asdf/installs/java/openjdk-17.0.2/bin/java -ea -Dhudson.Main.development=true -DRealJenkinsRule.location=file:/Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-test-harness/2129.v09f309d2339c/jenkins-test-harness-2129.v09f309d2339c.jar -DRealJenkinsRule.description=testLostNodeCleanedUpBySecondController(com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT) -DRealJenkinsRule.token=3d641647-f10c-4d35-896b-85b30830c2bc -DRealJenkinsRule.logging.com.google.jenkins.plugins.computeengine.CleanLostNodesWork=FINEST -Dwinstone.portFileName=/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/jenkins-port10162227027495641569.txt -agentlib:jdwp=transport=dt_socket,server=y,suspend=n -Dcom.google.jenkins.plugins.computeengine.CleanLostNodesWork.recurrencePeriod=60000 -jar /Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-war/2.452.3/jenkins-war-2.452.3.war --enable-future-java --httpPort=0 --httpListenAddress=127.0.0.1 --prefix=/jenkins
Listening for transport dt_socket at address: 58602
Running from: /Users/gbhat/.m2/repository/org/jenkins-ci/main/jenkins-war/2.452.3/jenkins-war-2.452.3.war
webroot: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/war
2025-01-07 20:56:46.956+0000 [id=1]	INFO	winstone.Logger#logInternal: Beginning extraction from war file
2025-01-07 20:56:47.714+0000 [id=1]	INFO	org.eclipse.jetty.server.Server#doStart: jetty-10.0.20; built: 2024-01-29T20:46:45.278Z; git: 3a745c71c23682146f262b99f4ddc4c1bc41630c; jvm 17.0.2+8-86
2025-01-07 20:56:47.822+0000 [id=1]	INFO	o.e.j.w.StandardDescriptorProcessor#visitServlet: NO JSP Support for /jenkins, did not find org.eclipse.jetty.jsp.JettyJspServlet
2025-01-07 20:56:47.837+0000 [id=1]	INFO	o.e.j.s.s.DefaultSessionIdManager#doStart: Session workerName=node0
2025-01-07 20:56:47.959+0000 [id=1]	INFO	hudson.WebAppMain#contextInitialized: Jenkins home directory: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157 found at: EnvVars.masterEnvVars.get("JENKINS_HOME")
2025-01-07 20:56:48.150+0000 [id=1]	INFO	o.e.j.s.handler.ContextHandler#doStart: Started w.@7d37f1c{Jenkins v2.452.3,/jenkins,file:///Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j%20h14001325888487977157/war/,AVAILABLE}{/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/war}
2025-01-07 20:56:48.155+0000 [id=1]	INFO	o.e.j.server.AbstractConnector#doStart: Started ServerConnector@27508c5d{HTTP/1.1, (http/1.1)}{127.0.0.1:58603}
2025-01-07 20:56:48.161+0000 [id=1]	INFO	org.eclipse.jetty.server.Server#doStart: Started Server@1a72a540{STARTING}[10.0.20,sto=0] @1365ms
2025-01-07 20:56:48.162+0000 [id=31]	INFO	winstone.Logger#logInternal: Winstone Servlet Engine running: controlPort=disabled
2025-01-07 20:56:48.237+0000 [id=40]	INFO	jenkins.InitReactorRunner$1#onAttained: Started initialization
2025-01-07 20:56:48.286+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/mina-sshd-api-core.jpi
2025-01-07 20:56:48.302+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/mina-sshd-api-common.jpi
2025-01-07 20:56:48.315+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/sshd.jpi
2025-01-07 20:56:48.324+0000 [id=61]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/javax-mail-api.jpi
2025-01-07 20:56:48.850+0000 [id=57]	WARNING	hudson.ClassicPluginStrategy#createClassJarFromWebInfClasses: Created /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/powershell/WEB-INF/lib/classes.jar; update plugin to a version created with a newer harness
2025-01-07 20:56:48.858+0000 [id=57]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/matrix-auth.jpi
2025-01-07 20:56:48.880+0000 [id=57]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/echarts-api.jpi
2025-01-07 20:56:49.082+0000 [id=57]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/jquery3-api.jpi
2025-01-07 20:56:49.089+0000 [id=57]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/junit.jpi
2025-01-07 20:56:49.095+0000 [id=57]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/matrix-project.jpi
2025-01-07 20:56:49.106+0000 [id=57]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/checks-api.jpi
2025-01-07 20:56:49.113+0000 [id=57]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/command-launcher.jpi
2025-01-07 20:56:49.119+0000 [id=57]	INFO	hudson.PluginManager#considerDetachedPlugin: Loading a detached plugin as a dependency: /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/plugins/jdk-tool.jpi
2025-01-07 20:56:49.356+0000 [id=61]	INFO	jenkins.InitReactorRunner$1#onAttained: Listed all plugins
RealJenkinsRule ready
2025-01-07 20:56:50.718+0000 [id=50]	INFO	jenkins.InitReactorRunner$1#onAttained: Prepared all plugins
2025-01-07 20:56:50.725+0000 [id=56]	INFO	jenkins.InitReactorRunner$1#onAttained: Started all plugins
2025-01-07 20:56:50.726+0000 [id=42]	INFO	jenkins.InitReactorRunner$1#onAttained: Augmented all extensions
2025-01-07 20:56:50.984+0000 [id=61]	INFO	jenkins.InitReactorRunner$1#onAttained: System config loaded
2025-01-07 20:56:51.014+0000 [id=49]	INFO	jenkins.InitReactorRunner$1#onAttained: System config adapted
2025-01-07 20:56:51.014+0000 [id=54]	INFO	jenkins.InitReactorRunner$1#onAttained: Loaded all jobs
2025-01-07 20:56:51.018+0000 [id=60]	INFO	jenkins.InitReactorRunner$1#onAttained: Configuration for all jobs updated
2025-01-07 20:56:51.022+0000 [id=43]	INFO	jenkins.model.Jenkins#setInstallState: Install state transitioning from: null to: TEST
2025-01-07 20:56:51.067+0000 [id=42]	INFO	jenkins.InitReactorRunner$1#onAttained: Completed initialization
2025-01-07 20:56:51.081+0000 [id=29]	INFO	hudson.lifecycle.Lifecycle#onReady: Jenkins is fully up and running
Checking status
Jenkins is running at http://localhost:58603/jenkins/
2025-01-07 20:56:51.240+0000 [id=24]	INFO	c.g.j.p.c.integration.ITUtil#bootDiskProject: Using boot disk project: tiger-team-testing
2025-01-07 20:56:51.241+0000 [id=24]	INFO	c.g.j.p.c.integration.ITUtil#bootDiskImageName: Using boot disk image: projects/tiger-team-testing/global/images/jenkins-gce-integration-test-jre
[p1#1]    0.000 Started
[p1#1]    0.001 [Pipeline] Start of Pipeline
[p1#1]    0.001 [Pipeline] node
[p1#1]   15.093 Still waiting to schedule task
[p1#1]   15.094 ‘Jenkins’ doesn’t have label ‘integration’
2025-01-07 20:57:38.031+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:57:38.042+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:57:39.341+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-07 20:57:39.341+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:57:44.534+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:57:44.541+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:57:45.790+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-07 20:57:45.790+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:58:26.400+0000 [id=80]	INFO	c.g.j.p.c.ComputeEngineCloud#provision: Provisioning node from configs [com.google.jenkins.plugins.computeengine.InstanceConfiguration@32446678] for excess workload of 1 units of label 'integration'
2025-01-07 20:58:27.333+0000 [id=80]	INFO	c.g.j.p.c.ComputeEngineCloud#availableNodeCapacity: Found capacity for 10 nodes in cloud integration
2025-01-07 20:58:27.337+0000 [id=80]	INFO	c.g.j.p.c.InstanceConfiguration#instance: User selected to use an autogenerated ssh key pair
2025-01-07 20:58:30.314+0000 [id=80]	INFO	c.g.j.p.c.InstanceConfiguration#provision: Sent insert request for instance configuration [integration]
2025-01-07 20:58:30.332+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineComputerLauncher#launch: Launch will wait 300000 for operation operation-1736283508649-62b2401c32ef3-2a834e56-09859659 to complete...
2025-01-07 20:58:30.347+0000 [id=80]	INFO	h.s.NodeProvisioner$StandardStrategyImpl#apply: Started provisioning integration-gg8fix from gce-integration with 1 executors. Remaining excess workload: 0
2025-01-07 20:58:30.347+0000 [id=127]	INFO	c.g.j.p.c.ComputeEngineCloud#lambda$getPlannedNodeFuture$0: Waiting 300000ms for node integration-gg8fix to connect
2025-01-07 20:58:38.032+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:58:38.036+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:58:38.853+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-07 20:58:38.854+0000 [id=79]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:58:44.533+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:58:44.534+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:58:45.341+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:58:45.342+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 1 local instances
2025-01-07 20:58:46.288+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Launching instance: integration-gg8fix
2025-01-07 20:58:46.290+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: bootstrap
2025-01-07 20:58:46.292+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Getting keypair...
2025-01-07 20:58:46.293+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Using autogenerated ssh keypair
2025-01-07 20:58:46.293+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Authenticating as jenkins
2025-01-07 20:58:46.932+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#updateLocalInstancesLabel: Updated label for instance integration-gg8fix
2025-01-07 20:58:47.739+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Connecting to 35.243.152.169 on port 22, with timeout 10000.
2025-01-07 20:58:53.036+0000 [id=124]	WARNING	c.g.j.p.c.ComputeEngineCloud#log: An error occured: There was a problem while connecting to 35.243.152.169:22
2025-01-07 20:58:59.566+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Connecting to 35.243.152.169 on port 22, with timeout 10000.
2025-01-07 20:59:02.575+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Connected via SSH.
2025-01-07 20:59:03.848+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Verifying: java -Dhudson.remoting.Launcher.pingIntervalSec=-1 -fullversion
2025-01-07 20:59:04.692+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Copying agent.jar to: /tmp
2025-01-07 20:59:07.909+0000 [id=124]	INFO	c.g.j.p.c.ComputeEngineCloud#log: Launching Jenkins agent via plugin SSH: java -Dhudson.remoting.Launcher.pingIntervalSec=-1 -jar /tmp/agent.jar
2025-01-07 20:59:34.229+0000 [id=127]	INFO	c.g.j.p.c.ComputeEngineCloud#lambda$getPlannedNodeFuture$0: 63882ms elapsed waiting for node integration-gg8fix to connect
[p1#1]  163.981 Running on integration-gg8fix in /tmp/workspace/p1
[p1#1]  163.981 [Pipeline] {
[p1#1]  163.981 [Pipeline] echo
[p1#1]  163.981 do first sleep
[p1#1]  163.981 [Pipeline] sleep
[p1#1]  163.981 Sleeping for 1 min 0 sec
2025-01-07 20:59:38.030+0000 [id=75]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:59:38.033+0000 [id=75]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:59:39.079+0000 [id=75]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:59:39.080+0000 [id=75]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 20:59:39.083+0000 [id=75]	FINEST	c.g.j.p.c.CleanLostNodesWork#isOrphaned: Instance integration-gg8fix last_refresh label value: 2025_01_07t20_58_45_343z, isOrphan: false
2025-01-07 20:59:44.528+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 20:59:44.529+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 20:59:45.362+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 20:59:45.362+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 1 local instances
2025-01-07 20:59:45.881+0000 [id=83]	FINEST	c.g.j.p.c.CleanLostNodesWork#updateLocalInstancesLabel: Updated label for instance integration-gg8fix
2025-01-07 21:00:36.542+0000 [id=87]	INFO	c.g.j.p.c.i.CleanLostNodesWorkIT#lambda$testLostNodeCleanedUpBySecondController$2db33b0f$1: Build is already running, can proceed to stopping jenkins to make the agent a lost VM
2025-01-07 21:00:36.562+0000 [id=167]	INFO	hudson.lifecycle.Lifecycle#onStop: Stopping Jenkins as requested by SYSTEM
2025-01-07 21:00:36.567+0000 [id=167]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Stopping Jenkins
2025-01-07 21:00:36.656+0000 [id=167]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Jenkins stopped
2025-01-07 21:00:36.701+0000 [id=32]	INFO	winstone.Logger#logInternal: JVM is terminating. Shutting down Jetty
2025-01-07 21:00:36.701+0000 [id=32]	INFO	org.eclipse.jetty.server.Server#doStop: Stopped Server@1a72a540{STOPPING}[10.0.20,sto=0]
2025-01-07 21:00:36.703+0000 [id=32]	INFO	o.e.j.server.AbstractConnector#doStop: Stopped ServerConnector@27508c5d{HTTP/1.1, (http/1.1)}{127.0.0.1:0}
2025-01-07 21:00:36.706+0000 [id=32]	INFO	o.e.j.s.handler.ContextHandler#doStop: Stopped w.@7d37f1c{Jenkins v2.452.3,/jenkins,null,STOPPED}{/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723/war}
2025-01-07 21:00:38.039+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 21:00:38.041+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 21:00:38.154+0000 [id=87]	INFO	c.g.j.p.c.i.CleanLostNodesWorkIT#lambda$testLostNodeCleanedUpBySecondController$2db33b0f$2: test sleeps for 240 seconds; so that the lost VM is detected by the second controller and it is deleted
2025-01-07 21:00:38.881+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 21:00:38.897+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 21:00:38.897+0000 [id=81]	FINEST	c.g.j.p.c.CleanLostNodesWork#isOrphaned: Instance integration-gg8fix last_refresh label value: 2025_01_07t20_59_45_363z, isOrphan: false
2025-01-07 22:40:19.566+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 22:40:19.569+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 22:40:21.085+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 1 running remote instances
2025-01-07 22:40:21.087+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-07 22:40:21.088+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#isOrphaned: Instance integration-gg8fix last_refresh label value: 2025_01_07t20_59_45_363z, isOrphan: true
2025-01-07 22:40:21.089+0000 [id=77]	INFO	c.g.j.p.c.CleanLostNodesWork#terminateInstance: Removing orphaned instance: integration-gg8fix
2025-01-07 23:57:36.624+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-07 23:57:36.629+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-07 23:57:37.845+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-07 23:57:37.845+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-08 00:34:03.976+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-08 00:34:03.980+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-08 00:34:04.913+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-08 00:34:04.914+0000 [id=77]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-08 02:51:02.273+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#doRun: Starting clean lost nodes worker
2025-01-08 02:51:02.277+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#cleanCloud: Cleaning cloud integration
2025-01-08 02:51:02.398+0000 [id=87]	INFO	c.g.j.p.c.i.CleanLostNodesWorkIT#lambda$testLostNodeCleanedUpBySecondController$2db33b0f$2: proceeding after sleep
2025-01-08 02:51:03.695+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#findRunningRemoteInstances: Found 0 running remote instances
2025-01-08 02:51:03.695+0000 [id=82]	FINEST	c.g.j.p.c.CleanLostNodesWork#findLocalInstances: Found 0 local instances
2025-01-08 02:51:04.642+0000 [id=87]	INFO	c.g.j.p.c.integration.ITUtil#teardownResources: teardown
2025-01-08 02:51:05.322+0000 [id=87]	INFO	c.g.j.p.c.integration.ITUtil#deleteIntegrationInstances: Cleaning up old instances; found 0 instances to delete, it may take a while for this deletion
Jan 08, 2025 8:21:05 AM org.jvnet.hudson.test.TemporaryDirectoryAllocator dispose
INFO: deleting /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h9076000789041025723
2025-01-08 02:51:05.714+0000 [id=135]	INFO	hudson.lifecycle.Lifecycle#onStop: Stopping Jenkins as requested by SYSTEM
2025-01-08 02:51:05.717+0000 [id=135]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Stopping Jenkins
2025-01-08 02:51:05.810+0000 [id=135]	INFO	hudson.lifecycle.Lifecycle#onStatusUpdate: Jenkins stopped
2025-01-08 02:51:05.852+0000 [id=32]	INFO	winstone.Logger#logInternal: JVM is terminating. Shutting down Jetty
2025-01-08 02:51:05.853+0000 [id=32]	INFO	org.eclipse.jetty.server.Server#doStop: Stopped Server@1a72a540{STOPPING}[10.0.20,sto=0]
2025-01-08 02:51:05.855+0000 [id=32]	INFO	o.e.j.server.AbstractConnector#doStop: Stopped ServerConnector@27508c5d{HTTP/1.1, (http/1.1)}{127.0.0.1:0}
2025-01-08 02:51:05.857+0000 [id=32]	INFO	o.e.j.s.handler.ContextHandler#doStop: Stopped w.@7d37f1c{Jenkins v2.452.3,/jenkins,null,STOPPED}{/Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157/war}
Jan 08, 2025 8:21:06 AM org.jvnet.hudson.test.TemporaryDirectoryAllocator dispose
INFO: deleting /Users/gbhat/CBProjects/google-compute-engine-plugin/target/tmp/j h14001325888487977157
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 21683 s -- in com.google.jenkins.plugins.computeengine.integration.CleanLostNodesWorkIT
[INFO]
[INFO] Results:
[INFO]
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0
[INFO]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  06:01 h
[INFO] Finished at: 2025-01-08T08:21:06+05:30
[INFO] ------------------------------------------------------------------------
➜  google-compute-engine-plugin git:(update-clean-lost-node)

Submitter checklist

  • Make sure you are opening from a topic/feature/bugfix branch (right side) and not your main branch!
  • Ensure that the pull request title represents the desired changelog entry
  • Please describe what you did
  • Link to relevant issues in GitHub or Jira
  • Link to relevant pull requests, esp. upstream and downstream changes
  • Ensure you have provided tests - that demonstrates feature works or fixes the issue

@gbhat618
clean lost node working
a91653c
@gbhat618
developing test
c3201ac
@gbhat618
revert the ITUtil changes
65bd743
@gbhat618
Squashed commit of the following:
40a1222 
commit 0f341b8
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 19:51:25 2025 +0530

    english grammer fix

commit 3071eae
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 15:15:30 2025 +0530

    print java version in the end of packer build for better logs

commit fd95fb5
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 14:53:02 2025 +0530

    english rewording better readability

commit 89cefb9
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 14:47:05 2025 +0530

    keep empty line - diff reduction

commit 7eb7d1a
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 14:40:52 2025 +0530

    spotless apply

commit 22514b3
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 14:38:26 2025 +0530

    fix the google creds to use correct constructor; java 21 image for agent, and clarifying contributor notes

commit a6c4140
Merge: 635271d c70e47e
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 12:41:12 2025 +0530

    Merge branch 'integration-test-updates' of github.com:gbhat618/google-compute-engine-plugin into integration-test-updates

commit 635271d
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 12:40:58 2025 +0530

    use java21 for agent image and simplify assertion jenkinsrule utilities

commit 35bd816
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 12:14:56 2025 +0530

    Use BuildWatcher instead of TailLog for simple

commit c70e47e
Author: Guruprasad Bhat <[email protected]>
Date:   Thu Jan 2 11:12:59 2025 +0530

    Update CONTRIBUTING.md

    Co-authored-by: Jesse Glick <[email protected]>

commit 12658e1
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 18:31:27 2024 +0530

    update jenkins test timeout

commit 79b8ffd
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 18:04:27 2024 +0530

    minor updates to integration tests and failsafe timeout

commit 35a9f74
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 16:47:58 2024 +0530

    remove the timeout config from documentation command

commit 37ad3df
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 16:47:10 2024 +0530

    pom update as per jenkins documentation

commit 4a49441
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 16:45:15 2024 +0530

    update some its for better test and assertions

commit 05b4e95
Author: guruprasad <[email protected]>
Date:   Fri Dec 20 16:32:55 2024 +0530

    update integration tests
@gbhat618
clean nodes in working - needs some more cleanup
b7de0f2
@gbhat618
Copy link
Contributor Author

gbhat618 commented Jan 4, 2025

PR requires #495

@gbhat618
Copy link
Contributor Author

gbhat618 commented Jan 6, 2025

👋 @jglick and @Vlatombe need help review this PR

jglick
jglick reviewed Jan 6, 2025
View reviewed changes
src/main/java/com/google/jenkins/plugins/computeengine/client/ComputeClientV2.java
* (<a href="https://github.com/GoogleCloudPlatform/gcp-plugin-core-java">gcp-plugin-core-java</a>, last updated in December 2019).
* Consideration for the gradual evolution of this class is suggested, including the re-implementation of methods
* currently utilized from the Graphite library, to ensure dependency solely on the Google API Java Client Services
* library (<a href="https://github.com/googleapis/google-api-java-client-services">google-api-java-client-services</a>).
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IIUC google-api-java-client-services corresponds to com.google.api.services packages?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yep that is correct. There is the Compute, and similarly the Instance classes are there, which are the same that graphite is importing as well.

So just now I tried to check a bit on the history of these classes,

Looking at the graphite library and our usages,

  • graphite library has total 6 client implementation (one of which is ComputeClient)
  • our usage is only these 6 classes 
    ✗ grep -h -r "import com.google.cloud.graphite.platforms.plugin.client" ./src | sort -u
import com.google.cloud.graphite.platforms.plugin.client.ClientFactory;
import com.google.cloud.graphite.platforms.plugin.client.ComputeClient.OperationException;
import com.google.cloud.graphite.platforms.plugin.client.ComputeClient;
import com.google.cloud.graphite.platforms.plugin.client.model.GuestAttribute;
import com.google.cloud.graphite.platforms.plugin.client.model.InstanceResourceData;
import com.google.cloud.graphite.platforms.plugin.client.util.ClientUtil;

So currently I am thinking like,

  • We should bring back the ComputeClient code from graphite into this repo back (as a separate PR); the ComputeClientV2 should be merged into the ComputeClient.
  • Another thought is, to fork the graphite into jenkinsci, but that means, we need to manage (possibly delete) the 5 unused client classes (and associated wrappers); which then leaves the repo with only 6 classes, so may not be a good idea to maintain a whole repo for just that.

Copy link
Member

@jglick jglick Jan 7, 2025 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we are making any major changes to the plugin (beyond what is necessary for this PR and specifically #503 (comment)), it should be to switch to whatever Java client library Google currently recommends, rather than maintaining our own stuff for no good reason.

gbhat618 and others added 14 commits January 7, 2025 10:18
@gbhat618 @Vlatombe
Update src/test/java/com/google/jenkins/plugins/computeengine/integra…
fe03a64 
…tion/CleanLostNodesWorkIT.java

Co-authored-by: Vincent Latombe <[email protected]>
@gbhat618 @Vlatombe
Update src/test/java/com/google/jenkins/plugins/computeengine/integra…
dcda478 
…tion/CleanLostNodesWorkIT.java

Co-authored-by: Vincent Latombe <[email protected]>
@gbhat618 @Vlatombe
Update src/test/java/com/google/jenkins/plugins/computeengine/integra…
92bd182 
…tion/CleanLostNodesWorkIT.java

Co-authored-by: Vincent Latombe <[email protected]>
@gbhat618 @Vlatombe
Update src/test/java/com/google/jenkins/plugins/computeengine/integra…
e47588d 
…tion/ComputeClientV2IT.java

Co-authored-by: Vincent Latombe <[email protected]>
@gbhat618 @jglick
Update src/main/java/com/google/jenkins/plugins/computeengine/CleanLo…
4e322d7 
…stNodesWork.java

Co-authored-by: Jesse Glick <[email protected]>
@gbhat618 @jglick
Update src/main/java/com/google/jenkins/plugins/computeengine/CleanLo…
9c840b5 
…stNodesWork.java

Co-authored-by: Jesse Glick <[email protected]>
@gbhat618 @jglick
Update src/test/java/com/google/jenkins/plugins/computeengine/integra…
f17d80e 
…tion/CleanLostNodesWorkIT.java

Co-authored-by: Jesse Glick <[email protected]>
@gbhat618 @jglick
Update src/test/java/com/google/jenkins/plugins/computeengine/integra…
6315666 
…tion/CleanLostNodesWorkIT.java

Co-authored-by: Jesse Glick <[email protected]>
@gbhat618
Squashed commit of the following:
4cd89ca 
commit 0f341b8
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 19:51:25 2025 +0530

    english grammer fix

commit 3071eae
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 15:15:30 2025 +0530

    print java version in the end of packer build for better logs

commit fd95fb5
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 14:53:02 2025 +0530

    english rewording better readability

commit 89cefb9
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 14:47:05 2025 +0530

    keep empty line - diff reduction

commit 7eb7d1a
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 14:40:52 2025 +0530

    spotless apply

commit 22514b3
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 14:38:26 2025 +0530

    fix the google creds to use correct constructor; java 21 image for agent, and clarifying contributor notes

commit a6c4140
Merge: 635271d c70e47e
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 12:41:12 2025 +0530

    Merge branch 'integration-test-updates' of github.com:gbhat618/google-compute-engine-plugin into integration-test-updates

commit 635271d
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 12:40:58 2025 +0530

    use java21 for agent image and simplify assertion jenkinsrule utilities

commit 35bd816
Author: guruprasad <[email protected]>
Date:   Thu Jan 2 12:14:56 2025 +0530

    Use BuildWatcher instead of TailLog for simple

commit c70e47e
Author: Guruprasad Bhat <[email protected]>
Date:   Thu Jan 2 11:12:59 2025 +0530

    Update CONTRIBUTING.md

    Co-authored-by: Jesse Glick <[email protected]>

commit 12658e1
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 18:31:27 2024 +0530

    update jenkins test timeout

commit 79b8ffd
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 18:04:27 2024 +0530

    minor updates to integration tests and failsafe timeout

commit 35a9f74
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 16:47:58 2024 +0530

    remove the timeout config from documentation command

commit 37ad3df
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 16:47:10 2024 +0530

    pom update as per jenkins documentation

commit 4a49441
Author: guruprasad <[email protected]>
Date:   Mon Dec 23 16:45:15 2024 +0530

    update some its for better test and assertions

commit 05b4e95
Author: guruprasad <[email protected]>
Date:   Fri Dec 20 16:32:55 2024 +0530

    update integration tests
@gbhat618
improve code and fix ComputeClientV2 intialization
5484655
@gbhat618
Revert "Squashed commit of the following:"
38bb7f6 
This reverts commit 4cd89ca.
@gbhat618
Merge branch 'develop' of github.com:jenkinsci/google-compute-engine-…
fabd527 
…plugin into update-clean-lost-node
@gbhat618
spotless
c243b28
@gbhat618
more accurate log message
1071692
@gbhat618 gbhat618 mentioned this pull request Jan 7, 2025
Open
@gbhat618 gbhat618 marked this pull request as ready for review January 7, 2025 20:10
@gbhat618 gbhat618 mentioned this pull request Jan 8, 2025
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@Vlatombe Vlatombe Vlatombe left review comments

@jglick jglick jglick approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
3 participants
@gbhat618 @jglick @Vlatombe