Creating a VM with a particular template is taking time

[ravirajkarasulli]

Jenkins and plugins versions report

Environment

OS: Linux - 6.8.0-1029-gcp
Java: 17.0.16 - Ubuntu (OpenJDK 64-Bit Server VM)
---
Office-365-Connector:5.1.0
Parameterized-Remote-Trigger:3.2.1
ace-editor:1.1
ansicolor:1.0.6
ant:513.vde9e7b_a_0da_0f
antisamy-markup-formatter:173.v680e3a_b_69ff3
apache-httpcomponents-client-4-api:4.5.14-269.vfa_2321039a_83
apache-httpcomponents-client-5-api:5.5-150.veb_76e719855b_
artifactory:4.0.8
asm-api:9.8-163.vb_2a_96d3f9c3c
authentication-tokens:1.144.v5ff4a_5ec5c33
aws-credentials:248.v78a_dcfc9db_ff
aws-java-sdk-ec2:1.12.780-480.v4a_0819121a_9e
aws-java-sdk-minimal:1.12.780-480.v4a_0819121a_9e
aws-java-sdk2-core:2.31.63-54.vcf1e5a_c56c49
aws-java-sdk2-ec2:2.31.63-54.vcf1e5a_c56c49
aws-java-sdk2-sts:2.29.34-8.v76857219b_b_92
blueocean:1.27.21
blueocean-bitbucket-pipeline:1.27.21
blueocean-commons:1.27.21
blueocean-config:1.27.21
blueocean-core-js:1.27.21
blueocean-dashboard:1.27.21
blueocean-display-url:2.4.4
blueocean-events:1.27.21
blueocean-git-pipeline:1.27.21
blueocean-github-pipeline:1.27.21
blueocean-i18n:1.27.21
blueocean-jwt:1.27.21
blueocean-personalization:1.27.21
blueocean-pipeline-api-impl:1.27.21
blueocean-pipeline-editor:1.27.21
blueocean-pipeline-scm-api:1.27.21
blueocean-rest:1.27.21
blueocean-rest-impl:1.27.21
blueocean-web:1.27.21
bootstrap5-api:5.3.7-2
bouncycastle-api:2.30.1.81-264.v95c79c0e772c
branch-api:2.1240.vca_710512d944
build-blocker-plugin:166.vc82fc20b_a_ed6
build-name-setter:2.5.1
build-timeout:1.38
build-timestamp:1.1.0
build-user-vars-plugin:195.v8c35f9d5c3dc
caffeine-api:3.2.2-178.v353b_8428ed56
checks-api:373.vfe7645102093
cloudbees-bitbucket-branch-source:936.4.4
cloudbees-credentials:3.3
cloudbees-folder:6.1037.v4cb_8573b_72a_a_
command-launcher:123.v37cfdc92ef67
commons-collections4-api:4.5.0-8.va_d5448ef9011
commons-httpclient3-api:3.1-3
commons-lang3-api:3.18.0-98.v3a_674c06072d
commons-text-api:1.14.0-194.v804a_dc3a_1b_d8
conditional-buildstep:1.5.0
config-file-provider:994.v3d4a_5fa_f353a_
credentials:1419.v2337d1ceceef
credentials-binding:702.vfe613e537e88
custom-folder-icon:2.21
date-parameter:58.v0ee8d1c59323
description-setter:264.v1957f215dcd5
display-upstream-changes:0.3.2
display-url-api:2.217.va_6b_de84cc74b_
docker-commons:457.v0f62a_94f11a_3
docker-workflow:621.va_73f881d9232
durable-task:595.ve87b_f1318d67
echarts-api:6.0.0-1
eddsa-api:0.3.0.1-19.vc432d923e5ee
email-ext:1925.v1598902b_58dd
emoji-symbols-api:16.0-26.v9818ff7423f0
envinject:2.926.v69c9b_3896a_96
envinject-api:1.235.va_14c74f8f487
environment-script:100.v3a_f1a_6a_b_7549
favorite:2.237.v79163ca_8b_892
file-parameters:385.v1cf03fdff8ce
flatpickr-api:4.6.13-18.vcf5f6a_5b_8468
flexible-publish:0.16.1
font-awesome-api:7.0.0-1
generic-webhook-trigger:2.3.1
gerrit-code-review:0.5.0
gerrit-trigger:2.42.0
git:5.7.0
git-client:6.3.0
git-server:137.ve0060b_432302
github:1.44.0
github-api:1.321-488.v9b_c0da_9533f8
github-branch-source:1834.v857721ea_74c6
github-oauth:651.v135e939e8b_60
github-pullrequest:0.7.2
google-compute-engine:4.683.v0ce26579a_ee7
google-oauth-plugin:1.335.ve6de40e2db_18
gradle:2.15
gson-api:2.13.1-153.vb_3d0c48a_a_b_4a_
handy-uri-templates-2-api:2.1.8-36.v85e4cb_234a_13
htmlpublisher:427
hudson-wsclean-plugin:1.0.8
instance-identity:203.v15e81a_1b_7a_38
ionicons-api:94.vcc3065403257
jackson2-api:2.19.2-408.v18248a_324cfe
jakarta-activation-api:2.1.3-2
jakarta-mail-api:2.1.3-2
javadoc:354.vee1a_660b_4990
javax-activation-api:1.2.0-8
javax-mail-api:1.6.2-11
jaxb:2.3.9-133.vb_ec76a_73f706
jdk-tool:83.v417146707a_3d
jenkins-design-language:1.27.21
jersey2-api:2.47-165.ve7809a_3e87e0
jfrog:1.5.8
jira:3.18
jira-integration:5.6.0-52.v095e44e20b_25
jjwt-api:0.11.5-120.v0268cf544b_89
jnr-posix-api:3.1.20-166.v50a_50932c65b_
job-import-plugin:122.v35289550f1e6
jobConfigHistory:1343.v4b_e819a_ecdc2
joda-time-api:2.14.0-149.v1c3ce991d1b_9
jquery3-api:3.7.1-583.vda_6ca_102270d
jsch:0.2.16-95.v3eecb_55fa_b_78
json-api:20250517-163.v1c5da_e99c775
json-path-api:2.9.0-178.vca_b_c71881321
jsoup:1.21.1-58.vfc578e6e2610
junit:1335.v6b_a_a_e18534e1
ldap:780.vcb_33c9a_e4332
mailer:515.vd788654779b_1
matrix-auth:3.2.7
matrix-project:849.v0cd64ed7e531
maven-plugin:3.26
mina-sshd-api-common:2.15.0-161.vb_200831a_c15b_
mina-sshd-api-core:2.15.0-161.vb_200831a_c15b_
momentjs:1.1.1
monitoring:2.5.0
multiple-scms:0.8
naginator:1.504.vfc3736332f16
nodelabelparameter:759.vb_b_e95db_f3251
nutanix-calm:1.2.2
oauth-credentials:0.657.v7d8dd90b_0382
okhttp-api:4.11.0-189.v976fa_d3379d6
oss-symbols-api:392.v27a_482d90083
pam-auth:1.12
parameterized-scheduler:285.ve611986d4c48
parameterized-trigger:873.v8b_e37dd8418f
pipeline-build-step:571.v08a_fffd4b_0ce
pipeline-github:2.8-162.382498405fdc
pipeline-github-lib:65.v203688e7727e
pipeline-graph-analysis:241.vc3d48fb_b_2582
pipeline-groovy-lib:752.vdddedf804e72
pipeline-input-step:534.v352f0a_e98918
pipeline-milestone-step:138.v78ca_76831a_43
pipeline-model-api:2.2258.v4e96d2b_da_f9b_
pipeline-model-definition:2.2258.v4e96d2b_da_f9b_
pipeline-model-extensions:2.2258.v4e96d2b_da_f9b_
pipeline-rest-api:2.38
pipeline-stage-step:322.vecffa_99f371c
pipeline-stage-tags-metadata:2.2258.v4e96d2b_da_f9b_
pipeline-stage-view:2.38
plain-credentials:199.v9f8e1f741799
plugin-util-api:6.1.0
popper2-api:2.11.6-5
preSCMbuildstep:115.vf9808414429d
pubsub-light:1.19
rebuild:338.va_0a_b_50e29397
repo:1.16.0
resource-disposer:0.25
run-condition:243.v3c3f94e46a_8b_
scm-api:707.v749f968369d4
script-security:1378.vf25626395f49
slack:795.v4b_9705b_e6d47
snakeyaml-api:2.3-125.v4d77857a_b_402
sonar:2.18
sonar-gerrit:388.v9b_f1cb_e42306
sse-gateway:1.28
ssh-credentials:361.vb_f6760818e8c
ssh-slaves:3.1071.v0d059c7b_c555
sshd:3.374.v19b_d59ce6610
structs:353.v261ea_40a_80fb_
timestamper:1.30
token-macro:477.vd4f0dc3cb_cf1
trilead-api:2.209.v0e69b_c43c245
variant:70.va_d9f17f859e0
workflow-aggregator:608.v67378e9d3db_1
workflow-api:1382.veca_a_efe062fa_
workflow-basic-steps:1079.vce64b_a_929c5a_
workflow-cps:4177.vb_203fe395445
workflow-durable-task-step:1446.v3efd13441220
workflow-job:1540.v295eccc9778f
workflow-multibranch:810.v6b_6e77da_7058
workflow-scm-step:437.v05a_f66b_e5ef8
workflow-step-api:706.v518c5dcb_24c0
workflow-support:976.vb_d9493c2eb_09
ws-cleanup:0.48

What Operating System are you using (both controller, and any agents involved in the problem)?

Controller: Ubuntu "22.04.5 LTS (Jammy Jellyfish)"
agent: Ubuntu 22

Reproduction steps

We are seeing delay in provisioning of VM for a particular label which was working fine but taking time to provision the VM itself.
We do not see any particular errors in the controller log but the Jenkins job keeps waiting for the provision of the VM defined by the template.
Same label worked without any issues.

After 30 minutes it provisioned the VM, I see below message in the jenkins.log

025-09-02 11:25:43.379+0000 [id=6852301] INFO c.g.j.p.c.ComputeEngineCloud#log: Launching instance: eee-eph-ing-smq7d2
2025-09-02 11:25:43.379+0000 [id=6852301] INFO c.g.j.p.c.ComputeEngineCloud#log: bootstrap
2025-09-02 11:25:43.379+0000 [id=6852301] INFO c.g.j.p.c.ComputeEngineCloud#log: Getting keypair...
2025-09-02 11:25:43.379+0000 [id=6852301] INFO c.g.j.p.c.ComputeEngineCloud#log: Using autogenerated ssh keypair
2025-09-02 11:25:43.379+0000 [id=6852301] INFO c.g.j.p.c.ComputeEngineCloud#log: Authenticating as jenkins
2025-09-02 11:25:43.554+0000 [id=6852301] INFO c.g.j.p.c.ComputeEngineCloud#log: Connecting to 10.132.1.68 on port 22, with timeout 10000.
2025-09-02 11:25:45.590+0000 [id=6852301] WARNING c.g.j.p.c.ComputeEngineCloud#log: An error occured: There was a problem while connecting to 10.32.1.68:22
2025-09-02 11:25:46.167+0000 [id=5979311] WARNING c.g.c.g.p.p.client.ComputeClient#lambda$waitForOperationCompletion$11: Error retrieving operation.
com.google.api.client.googleapis.json.GoogleJsonResponseException: 404 Not Found
GET https://compute.googleapis.com/compute/v1/projects/my-proj/zones/us-central1-a/operations/operation-1752616508754-639fed46e8b53-aa95e989-96126ddf
{
"code" : 404,
"errors" : [ {
"domain" : "global",
"message" : "The resource 'projects/my-proj/zones/us-central1-a/operations/operation-1752616-639fed46e-aa95e989-9612' was not found",
"reason" : "notFound"
} ],
"message" : "The resource 'projects/my-proj/zones/us-central1-a/operations/operation-1752616-639fed46e-aa95e989-9612' was not found"

I see a lot of operations not found messages in my jenkins.log file.

Expected Results

The VM created in a minute's time at the max

Actual Results

The VM creation taking a lot of time

Anything else?

No response

Are you interested in contributing a fix?

I could not.

[gbhat618]

[..] which was working fine but taking time to provision the VM [...] After 30 minutes it provisioned the VM [...]

1. Need to find when the VM creation request was sent to GCP, and when it actually completed the provisioning. This can be found from the GCP logging. If the GCP got the request to provision VM from Jenkins within few seconds of build trigger, but took lot of time to provision itself - it would be a problem on GCP side. Could be due to some quota settings on your GCP project or similar configurations.

2. There hasn't been any changes to the VM provisioning logic of this plugin, so leaning towards (1) for now.

[gbhat618]

If the GCP got the request to provision VM from Jenkins within few seconds of build trigger, but took lot of time to provision [...] Could be due to some quota settings on your GCP project or similar configurations.

in addition to the above - also would be good to double check if there are init scripts or startup scripts that are taking lot of time.

[ravirajkarasulli]

from the logs in GCP, I see the VM creation request is completed within 2 minutes but the whole provisioning process taking about 30 minutes. All the time, it is stuck saying "All nodes of label ‘LABEL’ are offline"

[gbhat618]

within 2 minutes but the whole provisioning process taking about 30 minutes

need to track down what is causing GCP to take so much time to provision. (perhaps some GCP quota is holding back from VM provisioning, or startup / init scripts taking time; delay appears to be not from Jenkins)

All the time, it is stuck saying "All nodes of label ‘LABEL’ are offline"

until the VM is provisioned and agent is launched build will be waiting for that agent, it is correct behavior.

[gbhat618]

maybe try to check if provisioning is fast in combination of

• different GCP project
• different VM image which already has java in it (something like https://github.com/jenkinsci/google-compute-engine-plugin/blob/develop/testimages/linux/setup-gce-image.sh), and not using any init / startup scripts.

[ravirajkarasulli]

This image has java available. I see other images working fine for provisioning the VM. Is there a way to find out when a request for provisioning a VM is created from Jenkins in jenkins log? Because, when I see the GCP logs there is only one entry for VM creation with the specified prefix in the request timeframe.

…

On Wed, Sep 3, 2025 at 1:58 PM Guruprasad Bhat ***@***.***> wrote: *gbhat618* left a comment (jenkinsci/google-compute-engine-plugin#526) <#526 (comment)> maybe try to check if provisioning is fast in combination of - different GCP project - different VM image which already has java in it (something like https://github.com/jenkinsci/google-compute-engine-plugin/blob/develop/testimages/linux/setup-gce-image.sh), and not using any init / startup scripts. — Reply to this email directly, view it on GitHub <#526 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AE544KBXJALDPCUB5BF2MJD3Q2RCLAVCNFSM6AAAAACFM6KRNGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZTENBYGIYTENRRG4> . You are receiving this because you authored the thread.Message ID: ***@***.***>

-- Regards, Raviraj

[gbhat618]

Is there a way to find out when a request for provisioning a VM is created from Jenkins in jenkins log?

grep for Sent insert request for instance configuration which is already logging at INFO level so should appear for each provisioning i think.

google-compute-engine-plugin/src/main/java/com/google/jenkins/plugins/computeengine/InstanceConfiguration.java

Line 335 in 0ce2657

log.info("Sent insert request for instance configuration [" + description + "]");

also grep for Provisioning node from configs which is also at INFO level should be appearing in jenkins logs.

google-compute-engine-plugin/src/main/java/com/google/jenkins/plugins/computeengine/ComputeEngineCloud.java

Lines 256 to 264 in 0ce2657

	log.log(
	Level.INFO,
	"Provisioning node from configs "
	+ configs
	+ " for excess workload of "
	+ excessWorkload
	+ " units of label '"
	+ label
	+ "'");

[ravirajkarasulli]

hi Guru,

I see many occurences of these strings in the log. I see stack trace like below.

2025-08-30 19:55:12.538+0000 [id=64] INFO c.g.j.p.c.InstanceConfiguration#provision: Sent insert request for instance configuration [Signing jobs]
2025-08-30 19:55:12.538+0000 [id=64] WARNING hudson.model.Slave#warnPlugin: com.google.jenkins.plugins.computeengine.ComputeEngineInstance or one of its superclass overrides readResolve() without calling super implementation.Please file an issue against the plugin implementing it: Plugin:google-compute-engine
2025-08-30 19:55:12.539+0000 [id=6040841] INFO c.g.j.p.c.ComputeEngineComputerLauncher#launch: Launch will wait 300000 for operation operation-1756583711590-63d9a8425c9ca-ba06fb88-4dc009d4 to complete...
2025-08-30 19:55:12.544+0000 [id=6038139] INFO c.g.j.p.c.ComputeEngineCloud#lambda$getPlannedNodeFuture$0: Waiting 300000ms for node my-prefix-kyucmd to connect
2025-08-30 19:55:15.648+0000 [id=5979311] WARNING c.g.c.g.p.p.client.ComputeClient#lambda$waitForOperationCompletion$11: Error retrieving operation.
com.google.api.client.googleapis.json.GoogleJsonResponseException: 404 Not Found
GET https://compute.googleapis.com/compute/v1/projects/my-proj/zones/us-central1-a/operations/operation-1752616508754-639fed46e8b53-aa95e989-96126ddf
{
"code" : 404,
"errors" : [ {
"domain" : "global",
"message" : "The resource 'projects/my-proj/zones/us-central1-a/operations/operation-1752616508754-639fed46e8b53-aa95e989-96126ddf' was not found",
"reason" : "notFound"
} ],
"message" : "The resource 'projects/my-proj/zones/us-central1-a/operations/operation-1752616508754-639fed46e8b53-aa95e989-96126ddf' was not found"
}
at PluginClassLoader for google-oauth-plugin//com.google.api.client.googleapis.json.GoogleJsonResponseException.from(GoogleJsonResponseException.java:146)
at PluginClassLoader for google-oauth-plugin//com.google.api.client.googleapis.services.json.AbstractGoogleJsonClientRequest.newExceptionOnError(AbstractGoogleJsonClientRequest.java:118)
at PluginClassLoader for google-oauth-plugin//com.google.api.client.googleapis.services.json.AbstractGoogleJsonClientRequest.newExceptionOnError(AbstractGoogleJsonClientRequest.java:37)
at PluginClassLoader for google-oauth-plugin//com.google.api.client.googleapis.services.AbstractGoogleClientRequest$1.interceptResponse(AbstractGoogleClientRequest.java:439)
at PluginClassLoader for google-oauth-plugin//com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1111)
at PluginClassLoader for google-oauth-plugin//com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:525)
at PluginClassLoader for google-oauth-plugin//com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:466)
at PluginClassLoader for google-oauth-plugin//com.google.api.client.googleapis.services.AbstractGoogleClientRequest.execute(AbstractGoogleClientRequest.java:576)
at PluginClassLoader for google-compute-engine//com.google.cloud.graphite.platforms.plugin.client.ComputeWrapper.getZoneOperation(ComputeWrapper.java:164)
at PluginClassLoader for google-compute-engine//com.google.cloud.graphite.platforms.plugin.client.ComputeClient.getZoneOperation(ComputeClient.java:584)
at PluginClassLoader for google-compute-engine//com.google.cloud.graphite.platforms.plugin.client.ComputeClient.lambda$waitForOperationCompletion$11(ComputeClient.java:673)
at PluginClassLoader for google-compute-engine//org.awaitility.core.CallableCondition$ConditionEvaluationWrapper.eval(CallableCondition.java:99)
at PluginClassLoader for google-compute-engine//org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:248)
at PluginClassLoader for google-compute-engine//org.awaitility.core.ConditionAwaiter$ConditionPoller.call(ConditionAwaiter.java:235)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)

Please let me know if they are relevant.

[gbhat618]

many occurences of these strings [...] stack trace like below

the logs are showing two separate insert options,
the first operation operation-1756583711590-63d9a8425c9ca-ba06fb88-4dc009d4 is still in waiting,
the 404 not found is coming for a different operation operation-1752616508754-639fed46e8b53-aa95e989-96126ddf ig.

Was there any corresponding

Launch will wait 300000 for operation [...]

for the failed operation operation-1752616508754-639fed46e8b53-aa95e989-96126ddf ?