Exception: Primary IP already assigned to another server

sandrinr commented 1 year ago

Jenkins and plugins versions report

Environment

```text Jenkins: 2.361.2 OS: Linux - 5.4.0-105-generic --- ace-editor:1.1 analysis-model-api:10.17.0 ansicolor:1.0.2 antisamy-markup-formatter:2.7 apache-httpcomponents-client-4-api:4.5.13-138.v4e7d9a_7b_a_e61 authentication-tokens:1.4 bootstrap5-api:5.2.1-3 bouncycastle-api:2.26 branch-api:2.1046.v0ca_37783ecc5 build-blocker-plugin:1.7.8 build-monitor-plugin:1.13+build.202205140447 caffeine-api:2.9.3-65.v6a_47d0f4d1fe checks-api:1.7.5 cloud-stats:0.27 cloudbees-folder:6.758.vfd75d09eea_a_1 cobertura:1.17 code-coverage-api:3.2.0 command-launcher:90.v669d7ccb_7c31 commons-lang3-api:3.12.0-36.vd97de6465d5b_ commons-text-api:1.10.0-27.vb_fa_3896786a_7 copyartifact:1.47 credentials:1189.vf61b_a_5e2f62e credentials-binding:523.vd859a_4b_122e6 dark-theme:245.vb_a_2b_b_010ea_96 data-tables-api:1.12.1-4 display-url-api:2.3.6 docker-commons:1.21 docker-workflow:521.v1a_a_dd2073b_2e downstream-build-cache:1.7 durable-task:501.ve5d4fc08b0be echarts-api:5.4.0-1 extended-read-permission:3.2 font-awesome-api:6.2.0-3 forensics-api:1.16.0 git:4.12.1 git-client:3.12.1 git-server:99.va_0826a_b_cdfa_d gitlab-api:5.0.1-78.v47a_45b_9f78b_7 gitlab-branch-source:640.v7101b_1c0def9 gitlab-plugin:1.5.35 handy-uri-templates-2-api:2.1.8-22.v77d5b_75e6953 hetzner-cloud:66.v5cb45cbd155e instance-identity:116.vf8f487400980 ionicons-api:28.va_f3a_84439e5f jackson2-api:2.13.4-293.vee957901b_6fb jacoco:3.3.2 jakarta-activation-api:2.0.1-2 jakarta-mail-api:2.0.1-2 javax-activation-api:1.2.0-5 javax-mail-api:1.6.2-8 jaxb:2.3.6-2 jdk-tool:55.v1b_32b_6ca_f9ca jersey2-api:2.37-1 jquery3-api:3.6.1-2 jsch:0.1.55.61.va_e9ee26616e7 junit:1153.v1c24f1a_d2553 lockable-resources:2.18 mailer:438.v02c7f0a_12fa_4 matrix-project:785.v06b_7f47b_c631 mina-sshd-api-common:2.9.1-44.v476733c11f82 mina-sshd-api-core:2.9.1-44.v476733c11f82 parameterized-trigger:2.45 pipeline-build-step:2.18 pipeline-groovy-lib:612.v84da_9c54906d pipeline-input-step:451.vf1a_a_4f405289 pipeline-milestone-step:101.vd572fef9d926 pipeline-model-api:2.2114.v2654ca_721309 pipeline-model-definition:2.2114.v2654ca_721309 pipeline-model-extensions:2.2114.v2654ca_721309 pipeline-stage-step:296.v5f6908f017a_5 pipeline-stage-tags-metadata:2.2114.v2654ca_721309 pipeline-utility-steps:2.13.0 plain-credentials:139.ved2b_9cf7587b plot:2.1.11 plugin-util-api:2.18.0 popper2-api:2.11.6-2 prism-api:1.29.0-1 role-strategy:562.v44e9a_e828d0e saml:4.354.vdc8c005cda_34 scm-api:621.vda_a_b_055e58f7 script-security:1183.v774b_0b_0a_a_451 scriptler:3.5 snakeyaml-api:1.32-86.ve3f030a_75631 ssh-agent:295.v9ca_a_1c7cc3a_a_ ssh-credentials:305.v8f4381501156 ssh-slaves:2.846.v1b_70190624f5 sshd:3.249.v2dc2ea_416e33 structs:324.va_f5d6774f3a_d theme-manager:1.5 timestamper:1.20 token-macro:308.v4f2b_ed62b_b_16 trilead-api:2.72.v2a_3236754f73 variant:59.vf075fe829ccb warnings-ng:9.20.1 workflow-aggregator:590.v6a_d052e5a_a_b_5 workflow-api:1198.v4596ea_5329b_6 workflow-basic-steps:994.vd57e3ca_46d24 workflow-cps:2802.v5ea_628154b_c2 workflow-durable-task-step:1199.v02b_9244f8064 workflow-job:1239.v71b_b_a_124a_725 workflow-multibranch:716.vc692a_e52371b_ workflow-scm-step:400.v6b_89a_1317c9a_ workflow-step-api:639.v6eca_cd8c04a_a_ workflow-support:838.va_3a_087b_4055b yet-another-build-visualizer:1.16 ```

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

Ubuntu 20.04

Reproduction steps

Use the Hetzner Cloud Plugin
Set the Primary IP setting to Allocate primary IPv4 using label selector, fail if none is available
Configure your Selector, in my case it is location=fsn
See the plugin working

Expected Results

Hetzner cloud nodes are allocated with the expected primary IPs set as expected.

Actual Results

From time to time we get the following exception

``` java.lang.IllegalStateException: Invalid API response : 422 at com.google.common.base.Preconditions.checkState(Preconditions.java:534) at cloud.dnation.jenkins.plugins.hetzner.Helper.assertValidResponse(Helper.java:114) at cloud.dnation.jenkins.plugins.hetzner.HetznerCloudResourceManager.createServer(HetznerCloudResourceManager.java:270) at cloud.dnation.jenkins.plugins.hetzner.NodeCallable.call(NodeCallable.java:42) at cloud.dnation.jenkins.plugins.hetzner.NodeCallable.call(NodeCallable.java:30) at jenkins.util.ContextResettingExecutorService$2.call(ContextResettingExecutorService.java:48) at jenkins.security.ImpersonatingExecutorService$2.call(ImpersonatingExecutorService.java:82) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) ```

Looking at the communication between Jenkins and the Hetzner API I can see:

<-- 422 https://api.hetzner.cloud/v1/servers (237ms)
[...]
{
  "error": {
    "message": "primary ip already assigned to another server",
    "code": "primary_ip_assigned",
    "details": null
  }
}

Anything else?

I think the issue is not that severe. The plugin will try again and until now I did not end up in a situation where this continued to happen in a short period of time.

But nevertheless, it seems that there is some race going on and/or some tracking missing on Jenkins's side.

These IPs are used by Jenkins alone, there is no interference from external sources.

vanlueckn commented 1 year ago

@sandrinr Where did you find the logs of the hetzner api calls?

sandrinr commented 1 year ago

@vanlueckn It was a combination of using Jenkins Systems Log feature with a log recorder using the pattern cloud.dnation.jenkins.plugins.hetzner plus the standard Jenkins log written to standard out in a Docker environment (how we run Jenkins).

rkosegi commented 1 year ago

@sandrinr @vanlueckn this is now properly documented

jenkinsci / hetzner-cloud-plugin