intermittent error "reserved port collision" when running new job

[habibiefaried]

Nomad version

Nomad v1.0.0-beta3 (fcb32ef)

Operating system and Environment details

Distributor ID: Debian
Description: Debian GNU/Linux 10 (buster)
Release: 10
Codename: buster

Issue

Sometimes, whenever I update or run a new job. I got error max-plan-attempts failed on its UI

Reproduction steps

Just run a job file

Job file (if appropriate)

Taken from: https://www.hashicorp.com/blog/consul-connect-native-tasks-in-hashicorp-nomad-0-12

job "cn-demo" {
      datacenters = ["dc1"]

      group "generator" {
        network {
          port "api" {}
        }

        service {
          name = "uuid-api"
          port = "${NOMAD_PORT_api}"

          connect {
            native = true
          }
        }

        task "generate" {
          driver = "docker"

          config {
            image        = "hashicorpnomad/uuid-api:v3"
            network_mode = "host"
          }

          env {
            BIND = "0.0.0.0"
            PORT = "${NOMAD_PORT_api}"
          }
        }
      }

      group "frontend" {
        network {
          port "http" {
            static = 9800
          }
        }

        service {
          name = "uuid-fe"
          port = "9800"

          connect {
            native = true
          }
        }

        task "frontend" {
          driver = "docker"

          config {
            image        = "hashicorpnomad/uuid-fe:v3"
            network_mode = "host"
          }

          env {
            UPSTREAM = "uuid-api"
            BIND     = "0.0.0.0"
            PORT     = "9800"
          }
        }
      }
    }

Nomad Client logs (if appropriate)

2020-12-03T05:32:38.511+0100 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration=442.672µs
    2020-12-03T05:32:48.516+0100 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration=1.008414ms
    2020-12-03T05:32:58.534+0100 [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=client duration=900.343µs

Nomad Server logs (if appropriate)

2020-12-03T05:33:01.954+0100 [DEBUG] worker: submitted plan for evaluation: eval_id=098a520b-4cd9-78a3-6ba2-613d94b33823
    2020-12-03T05:33:01.954+0100 [DEBUG] worker: refreshing state: refresh_index=345 eval_id=098a520b-4cd9-78a3-6ba2-613d94b33823
    2020-12-03T05:33:01.954+0100 [DEBUG] worker.service_sched: refresh forced: eval_id=098a520b-4cd9-78a3-6ba2-613d94b33823 job_id=cn-demo namespace=default
    2020-12-03T05:33:01.954+0100 [DEBUG] worker.service_sched: reconciled current state with desired state: eval_id=098a520b-4cd9-78a3-6ba2-613d94b33823 job_id=cn-demo namespace=default results="Total changes: (place 2) (destructive 0) (inplace 0) (stop 0)
Desired Changes for "generator": (place 1) (inplace 0) (destructive 0) (stop 0) (migrate 0) (ignore 0) (canary 0)
Desired Changes for "frontend": (place 1) (inplace 0) (destructive 0) (stop 0) (migrate 0) (ignore 0) (canary 0)"
    2020-12-03T05:33:01.987+0100 [DEBUG] nomad: plan for node rejected: node_id=9fa84370-c713-b914-d329-f6485951cddc reason="reserved port collision" eval_id=098a5

Nomad Server Config

bind_addr = "0.0.0.0"
log_level = "DEBUG"
data_dir = "/etc/nomad"
name = "vmi483776.contaboserver.net"
server {
  enabled = true
  bootstrap_expect = 1
  raft_protocol = 3
}
advertise {
  http = "161.97.158.38"
  rpc = "161.97.158.38"
  serf = "161.97.158.38"
}
consul {
  address = "127.0.0.1:8500"
  auto_advertise = true
  server_auto_join = true
  client_auto_join = true
}
autopilot {
  cleanup_dead_servers      = true
  last_contact_threshold    = "200ms"
  max_trailing_logs         = 2500
  server_stabilization_time = "10s"
  enable_redundancy_zones   = false
  disable_upgrade_migration = false
  enable_custom_upgrades    = false
}

Nomad Client config

bind_addr = "0.0.0.0"
log_level = "DEBUG"
data_dir = "/etc/nomad"
name = "vmi483778.contaboserver.net"
client {
  enabled = true
  reserved {
    reserved_ports = "22,53,68,111,8301,8500,8600,32768-60999"
  }
}
advertise {
  http = "161.97.158.40"
  rpc = "161.97.158.40"
  serf = "161.97.158.40"
}
consul {
  address = "127.0.0.1:8500"
  auto_advertise = true
  server_auto_join = true
  client_auto_join = true
}

Notes

Btw you can really visit this url: http://161.97.158.38:4646/ui/jobs/cn-demo. It's my testbed server for this nomad beta version. It's opened and unauthenticated, in which you can try to see it live

Thanks

[vincenthuynh]

I'm seeing the same issue too: https://discuss.hashicorp.com/t/evaluation-maximum-attempts-reached-5/18449

[rgl]

I'm also observing this. But my job does not even exposes any port, so I'm a bit confused about the error message:

job "damon" {
  datacenters = ["dc1"]
  group "damon" {
    count = 1
    task "damon" {
      driver = "raw_exec"
      artifact {
        source = "https://github.com/rgl/damon/releases/download/v0.1.2/damon.zip"
      }
      template {
        destination = "local/example.ps1"
        data = <<-EOD
...
        EOD
      }
      config {
        command = "local/damon.exe"
        args = [
          "PowerShell.exe",
          "-File",
          "local/example.ps1"
        ]
      }
      resources {
        cpu = 100
        memory = 350
      }
    }
  }
}

Also, is there a better way to gather these errors messages besides monitoring the client logs from the nomad ui (e.g. http://localhost:4646/ui/clients/c9d4d1c5-51cc-7276-0949-638d0072061e/monitor?level=debug)?

It would be pretty nice to see these errors from e.g. http://localhost:4646/ui/jobs/damon/evaluations. For my particular problem, it only shows something like max-plan-attempts | failed | False.

I'm not sure if it makes any difference, but I'm running nomad in Windows Server 2019.

[habibiefaried]

Yes I agree. This kind of error should be visible from the UI of failed job.

Btw, I have a weird workaround for this bug. So, you can just restart all nomad servers and eventually, this job will be re-run again successfully. I've done it on my cluster multiple times.

However, not sure if I have to do this periodically -__-'

[habibiefaried]

Btw I have the solid workaround for this. So I did these steps:

1. Restarting all nomad servers
2. Stop that pending task
3. Re-run the same task

Well, at least I have this workaround. Hoping this will be useful for fellow users as well.

[tgross]

Hi @habibiefaried it looks like you're running into another example of #9492. The port reservation is only honored for static ports, not dynamic ports.

We intend to fix this (see #8186) and have a community-provided PR #8478 that doesn't seem like it's going to make it over the finish line so we're going to have to circle back to that.

[exFalso]

Getting this as well on 0.12, but the workaround doesn't work. The error seems persistent, I cannot run any job atm on the cluster, they all result in reserved port collision. Tried restarting servers+clients, stopping/restarting all jobs.

[exFalso]

Ok what worked:

1. Stopped all servers
2. Manually wiped server folders
3. restart servers
4. restart clients