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

Nomad 0.6.0-rc1: Nomad Client deregisters Server from Consul. Regression of #525 #2827

Closed
marcjay opened this issue Jul 12, 2017 · 3 comments
Closed

Nomad 0.6.0-rc1: Nomad Client deregisters Server from Consul. Regression of #525 #2827

marcjay opened this issue Jul 12, 2017 · 3 comments
Assignees
@schmichael
Labels
theme/consul type/bug

Comments

@marcjay
Copy link

marcjay commented Jul 12, 2017

Nomad version

Nomad v0.6.0-rc1 (5187fcf+CHANGES)

Operating system and Environment details

Ubuntu - Vagrantfile: https://github.com/hashicorp/nomad/blob/master/demo/vagrant/Vagrantfile

Issue

Running a Nomad agent in client mode on the same host as a Nomad agent running in server mode causes registration conflicts in Consul. This appears to be a regression of #525. Appreciate that the recommended best practise is to run separate server and client hosts in production, and that an agent can run in both client and server mode at the same time, however this was not an issue with 0.5.6. We run both client and server on the same host in dev (Vagrant VM) to more closely match production where we deploy them to separate instances.

Reproduction steps

  1. vagrant up the quickstart Vagrantfile: https://github.com/hashicorp/nomad/blob/master/demo/vagrant/Vagrantfile
  2. wget https://github.com/hashicorp/nomad/blob/master/demo/vagrant/server.hcl and https://raw.githubusercontent.com/hashicorp/nomad/master/demo/vagrant/client1.hcl to the VM
  3. Start the server: sudo nomad agent -config server.hcl
  4. Start the client: sudo nomad agent -config client1.hcl
  5. Tail /var/log/syslog to see the deregistration occur in Consul
  6. Run curl http://127.0.0.1:8500/v1/catalog/services. Expect to see:
{
    "consul": [],
    "nomad": [
        "http",
        "rpc",
        "serf"
    ],
    "nomad-client": [
        "http"
    ]
}

Actually see:

{
    "consul": [],
    "nomad-client": [
        "http"
    ]
}

Attempting to start up any further clients will fail as it cannot locate the Nomad server instance using Consul. As I said, this was not an issue in 0.5.6

Nomad Server logs (if appropriate)

vagrant@nomad:~$ sudo nomad agent -config server.hcl
==> WARNING: Bootstrap mode enabled! Potentially unsafe operation.
    Loaded configuration from server.hcl
==> Starting Nomad agent...
==> Nomad agent configuration:

                 Atlas: <disabled>
                Client: false
             Log Level: DEBUG
                Region: global (DC: dc1)
                Server: true
               Version: 0.6.0rc1

==> Nomad agent started! Log data will stream in below:

    2017/07/12 17:49:59 [INFO] raft: Initial configuration (index=1): [{Suffrage:Voter ID:10.0.2.15:4647 Address:10.0.2.15:4647}]
    2017/07/12 17:49:59 [INFO] serf: EventMemberJoin: nomad.global 10.0.2.15
    2017/07/12 17:49:59.125493 [INFO] nomad: starting 1 scheduling worker(s) for [batch system service _core]
    2017/07/12 17:49:59 [INFO] raft: Node at 10.0.2.15:4647 [Follower] entering Follower state (Leader: "")
    2017/07/12 17:49:59 [WARN] serf: Failed to re-join any previously known node
    2017/07/12 17:49:59.133236 [INFO] nomad: adding server nomad.global (Addr: 10.0.2.15:4647) (DC: dc1)
    2017/07/12 17:49:59.133793 [DEBUG] server.nomad: lost contact with Nomad quorum, falling back to Consul for server list
    2017/07/12 17:49:59.169632 [DEBUG] consul.sync: registered 3 services, 3 checks; deregistered 0 services, 0 checks
    2017/07/12 17:50:00 [WARN] raft: Heartbeat timeout from "" reached, starting election
    2017/07/12 17:50:00 [INFO] raft: Node at 10.0.2.15:4647 [Candidate] entering Candidate state in term 3
    2017/07/12 17:50:00 [DEBUG] raft: Votes needed: 1
    2017/07/12 17:50:00 [DEBUG] raft: Vote granted from 10.0.2.15:4647 in term 3. Tally: 1
    2017/07/12 17:50:00 [INFO] raft: Election won. Tally: 1
    2017/07/12 17:50:00 [INFO] raft: Node at 10.0.2.15:4647 [Leader] entering Leader state
    2017/07/12 17:50:00.733153 [INFO] nomad: cluster leadership acquired
    2017/07/12 17:50:00.736016 [DEBUG] leader: reconciling job summaries at index: 6
    2017/07/12 17:50:03 [DEBUG] memberlist: TCP connection from=127.0.0.1:52444
    2017/07/12 17:50:04.533981 [DEBUG] http: Request /v1/status/peers (256.219µs)

Nomad Client logs (if appropriate)

vagrant@nomad:~$ sudo nomad agent -config client1.hcl
    Loaded configuration from client1.hcl
==> Starting Nomad agent...
==> Nomad agent configuration:

                 Atlas: <disabled>
                Client: true
             Log Level: DEBUG
                Region: global (DC: dc1)
                Server: false
               Version: 0.6.0rc1

==> Nomad agent started! Log data will stream in below:

    2017/07/12 17:50:09.418604 [INFO] client: using state directory /tmp/client1/client
    2017/07/12 17:50:09.418679 [INFO] client: using alloc directory /tmp/client1/alloc
    2017/07/12 17:50:09.419911 [DEBUG] client: built-in fingerprints: [arch cgroup consul cpu host memory network nomad signal storage vault env_aws env_gce]
    2017/07/12 17:50:09.420106 [INFO] fingerprint.cgroups: cgroups are available
    2017/07/12 17:50:09.420540 [DEBUG] client: fingerprinting cgroup every 15s
    2017/07/12 17:50:09.422969 [INFO] fingerprint.consul: consul agent is available
    2017/07/12 17:50:09.423252 [DEBUG] fingerprint.cpu: frequency: 3099 MHz
    2017/07/12 17:50:09.423257 [DEBUG] fingerprint.cpu: core count: 1
    2017/07/12 17:50:09.428781 [DEBUG] client: fingerprinting consul every 15s
    2017/07/12 17:50:09.429017 [DEBUG] fingerprint.network: link speed for enp0s3 set to 1000
    2017/07/12 17:50:09.429074 [DEBUG] fingerprint.network: Detected interface enp0s3 with IP: 10.0.2.15
    2017/07/12 17:50:09.431157 [DEBUG] client: fingerprinting vault every 15s
    2017/07/12 17:50:09.431707 [DEBUG] fingerprint.env_aws: Error querying AWS Metadata URL, skipping
    2017/07/12 17:50:09.432749 [DEBUG] fingerprint.env_gce: Could not read value for attribute "machine-type"
    2017/07/12 17:50:09.432762 [DEBUG] fingerprint.env_gce: Error querying GCE Metadata URL, skipping
    2017/07/12 17:50:09.432781 [DEBUG] client: applied fingerprints [arch cgroup consul cpu host memory network nomad signal storage]
    2017/07/12 17:50:09.432802 [DEBUG] driver.docker: using client connection initialized from environment
    2017/07/12 17:50:09.446198 [DEBUG] driver.exec: exec driver is enabled
    2017/07/12 17:50:09.446281 [WARN] driver.raw_exec: raw exec is enabled. Only enable if needed
    2017/07/12 17:50:09.446641 [DEBUG] client: available drivers [docker exec raw_exec]
    2017/07/12 17:50:09.448195 [INFO] client: Node ID "2a91096d-cffd-21ca-23fd-a336827f82da"
    2017/07/12 17:50:09.451314 [DEBUG] client: fingerprinting docker every 15s
    2017/07/12 17:50:09.452465 [DEBUG] client: fingerprinting exec every 15s
    2017/07/12 17:50:09.452508 [DEBUG] client: fingerprinting rkt every 15s
    2017/07/12 17:50:09.466519 [DEBUG] client: updated allocations at index 1 (total 0) (pulled 0) (filtered 0)
    2017/07/12 17:50:09.470907 [DEBUG] client: allocs: (added 0) (removed 0) (updated 0) (ignore 0)
    2017/07/12 17:50:09.471693 [INFO] client: node registration complete
    2017/07/12 17:50:09.472221 [DEBUG] client: periodically checking for node changes at duration 5s
    2017/07/12 17:50:09.495959 [DEBUG] consul.sync: registered 1 services, 1 checks; deregistered 3 services, 3 checks
    2017/07/12 17:50:11.167716 [DEBUG] http: Request /v1/agent/servers (148.618µs)
    2017/07/12 17:50:11.575749 [DEBUG] client: state updated to ready
    2017/07/12 17:50:21.169828 [DEBUG] http: Request /v1/agent/servers (18.546µs)
    2017/07/12 17:50:31.176132 [DEBUG] http: Request /v1/agent/servers (360.942µs)
==> Failed to check for updates: Get https://checkpoint-api.hashicorp.com/v1/check/nomad?arch=amd64&os=linux&signature=46fd42d2-a37a-b5fe-30cd-efda929ab30c&version=0.6.0-rc1: dial tcp: lookup checkpoint-api.hashicorp.com on 10.0.2.3:53: no such host
    2017/07/12 17:50:41.181479 [DEBUG] http: Request /v1/agent/servers (22.331µs)
    2017/07/12 17:50:51.184419 [DEBUG] http: Request /v1/agent/servers (32.129µs)
    2017/07/12 17:51:01.189343 [DEBUG] http: Request /v1/agent/servers (259.551µs)
    2017/07/12 17:51:11.193204 [DEBUG] http: Request /v1/agent/servers (321.107µs)
    2017/07/12 17:51:21.196111 [DEBUG] http: Request /v1/agent/servers (24.49µs)
    2017/07/12 17:51:31.199228 [DEBUG] http: Request /v1/agent/servers (25.069µs)
    2017/07/12 17:51:41.203810 [DEBUG] http: Request /v1/agent/servers (168.515µs)
    2017/07/12 17:51:51.210363 [DEBUG] http: Request /v1/agent/servers (90.306µs)
    2017/07/12 17:52:01.214621 [DEBUG] http: Request /v1/agent/servers (17.746µs)
    2017/07/12 17:52:11.216534 [DEBUG] http: Request /v1/agent/servers (109.695µs)
    2017/07/12 17:52:21.218243 [DEBUG] http: Request /v1/agent/servers (19.133µs)
    2017/07/12 17:52:31.220265 [DEBUG] http: Request /v1/agent/servers (19.536µs)
    2017/07/12 17:52:41.221991 [DEBUG] http: Request /v1/agent/servers (133.486µs)
    2017/07/12 17:52:51.224287 [DEBUG] http: Request /v1/agent/servers (19.853µs)
    2017/07/12 17:53:01.226570 [DEBUG] http: Request /v1/agent/servers (17.907µs)
    2017/07/12 17:53:11.229780 [DEBUG] http: Request /v1/agent/servers (124.954µs)
    2017/07/12 17:53:21.231643 [DEBUG] http: Request /v1/agent/servers (20.829µs)
    2017/07/12 17:53:31.234696 [DEBUG] http: Request /v1/agent/servers (18.058µs)
    2017/07/12 17:53:41.236708 [DEBUG] http: Request /v1/agent/servers (105.857µs)
    2017/07/12 17:53:51.238733 [DEBUG] http: Request /v1/agent/servers (16.956µs)
    2017/07/12 17:54:01.241400 [DEBUG] http: Request /v1/agent/servers (24.624µs)
    2017/07/12 17:54:11.245893 [DEBUG] http: Request /v1/agent/servers (165.782µs)
    2017/07/12 17:54:21.248151 [DEBUG] http: Request /v1/agent/servers (17.021µs)
    2017/07/12 17:54:31.250134 [DEBUG] http: Request /v1/agent/servers (16.666µs)
    2017/07/12 17:54:41.252013 [DEBUG] http: Request /v1/agent/servers (121.677µs)
    2017/07/12 17:54:51.254906 [DEBUG] http: Request /v1/agent/servers (29.115µs)
    2017/07/12 17:55:01.258048 [DEBUG] http: Request /v1/agent/servers (26.286µs)
    2017/07/12 17:55:11.260586 [DEBUG] http: Request /v1/agent/servers (17.679µs)
    2017/07/12 17:55:11.505594 [DEBUG] client: updated allocations at index 1 (total 0) (pulled 0) (filtered 0)
    2017/07/12 17:55:11.506207 [DEBUG] client: allocs: (added 0) (removed 0) (updated 0) (ignore 0)
    2017/07/12 17:55:21.265863 [DEBUG] http: Request /v1/agent/servers (112.909µs)

Consul Logs

Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request GET /v1/agent/self (453.553µs) from=127.0.0.1:44390
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request GET /v1/catalog/datacenters (228.483µs) from=127.0.0.1:44390
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request GET /v1/agent/services (54.567µs) from=127.0.0.1:44392
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request GET /v1/catalog/service/nomad?dc=dc1&near=_agent&stale=&tag=serf&wait=2000ms (64.93µs) from=127.0.0.1:44390
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request GET /v1/agent/checks (23.196µs) from=127.0.0.1:44392
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [INFO] agent: Synced service '_nomad-server-nomad-rpc'
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request PUT /v1/agent/service/register (940.236µs) from=127.0.0.1:44392
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [INFO] agent: Synced service '_nomad-server-nomad-serf'
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request PUT /v1/agent/service/register (2.254365ms) from=127.0.0.1:44392
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [INFO] agent: Synced service '_nomad-server-nomad-http'
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request PUT /v1/agent/service/register (3.623399ms) from=127.0.0.1:44392
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [INFO] agent: Synced check '2ec4946c94a5127113067f4cde72dab778ef383a'
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request PUT /v1/agent/check/register (8.12025ms) from=127.0.0.1:44392
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [INFO] agent: Synced check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183'
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request PUT /v1/agent/check/register (412.962µs) from=127.0.0.1:44392
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: pausing 3.227674765s before first socket connection of 0.0.0.0:4647
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [INFO] agent: Synced check '7deb911342190a84af99c63552bdfb202fe6fadb'
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] http: Request PUT /v1/agent/check/register (461.536µs) from=127.0.0.1:44392
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: pausing 4.204252933s before first socket connection of 0.0.0.0:4648
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: pausing 5.361043941s before first HTTP request of http://0.0.0.0:4646/v1/status/peers
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '7deb911342190a84af99c63552bdfb202fe6fadb' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:49:59 nomad consul[1126]:     2017/07/12 17:49:59 [DEBUG] agent: Node info in sync
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' is passing
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [INFO] agent: Synced check '2ec4946c94a5127113067f4cde72dab778ef383a'
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [DEBUG] agent: Check '7deb911342190a84af99c63552bdfb202fe6fadb' in sync
Jul 12 17:50:02 nomad consul[1126]:     2017/07/12 17:50:02 [DEBUG] agent: Node info in sync
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' is passing
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [INFO] agent: Synced check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183'
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [DEBUG] agent: Check '7deb911342190a84af99c63552bdfb202fe6fadb' in sync
Jul 12 17:50:03 nomad consul[1126]:     2017/07/12 17:50:03 [DEBUG] agent: Node info in sync
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [DEBUG] agent: Check '7deb911342190a84af99c63552bdfb202fe6fadb' is passing
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [DEBUG] agent: Service '_nomad-server-nomad-http' in sync
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [INFO] agent: Synced check '7deb911342190a84af99c63552bdfb202fe6fadb'
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:50:04 nomad consul[1126]:     2017/07/12 17:50:04 [DEBUG] agent: Node info in sync

Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request GET /v1/agent/self (660.434µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request GET /v1/agent/self (327.9µs) from=127.0.0.1:44402
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request GET /v1/agent/services (137.274µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request GET /v1/agent/checks (83.135µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: removed check "7deb911342190a84af99c63552bdfb202fe6fadb"
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered service '_nomad-server-nomad-http'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered check '7deb911342190a84af99c63552bdfb202fe6fadb'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request PUT /v1/agent/service/deregister/_nomad-server-nomad-http (6.226777ms) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-server-nomad-rpc' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Check '2ec4946c94a5127113067f4cde72dab778ef383a' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: removed check "2ec4946c94a5127113067f4cde72dab778ef383a"
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered service '_nomad-server-nomad-rpc'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-server-nomad-serf' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered check '2ec4946c94a5127113067f4cde72dab778ef383a'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request PUT /v1/agent/service/deregister/_nomad-server-nomad-rpc (6.316796ms) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: removed check "1cd33e4eeebcb8286d83a93fdc2d4b071a572183"
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered service '_nomad-server-nomad-serf'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request PUT /v1/agent/service/deregister/_nomad-server-nomad-serf (717.633µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Synced service '_nomad-client-nomad-client-http'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request PUT /v1/agent/service/register (384.932µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: removed check "1cd33e4eeebcb8286d83a93fdc2d4b071a572183"
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered check '1cd33e4eeebcb8286d83a93fdc2d4b071a572183'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request PUT /v1/agent/check/deregister/1cd33e4eeebcb8286d83a93fdc2d4b071a572183 (107.336µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: removed check "2ec4946c94a5127113067f4cde72dab778ef383a"
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered check '2ec4946c94a5127113067f4cde72dab778ef383a'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request PUT /v1/agent/check/deregister/2ec4946c94a5127113067f4cde72dab778ef383a (159.123µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: removed check "7deb911342190a84af99c63552bdfb202fe6fadb"
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Deregistered check '7deb911342190a84af99c63552bdfb202fe6fadb'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request PUT /v1/agent/check/deregister/7deb911342190a84af99c63552bdfb202fe6fadb (122.842µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Synced check '99808528a94be6b0968ec34200b1693571b658cd'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] http: Request PUT /v1/agent/check/register (708.585µs) from=127.0.0.1:44400
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: pausing 1.668125857s before first HTTP request of http://0.0.0.0:5656/v1/agent/servers
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Check '99808528a94be6b0968ec34200b1693571b658cd' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [INFO] agent: Synced check '99808528a94be6b0968ec34200b1693571b658cd'
Jul 12 17:50:09 nomad consul[1126]:     2017/07/12 17:50:09 [DEBUG] agent: Node info in sync
Jul 12 17:50:11 nomad consul[1126]:     2017/07/12 17:50:11 [DEBUG] agent: Check '99808528a94be6b0968ec34200b1693571b658cd' is passing
Jul 12 17:50:11 nomad consul[1126]:     2017/07/12 17:50:11 [DEBUG] agent: Service 'consul' in sync
Jul 12 17:50:11 nomad consul[1126]:     2017/07/12 17:50:11 [DEBUG] agent: Service '_nomad-client-nomad-client-http' in sync
Jul 12 17:50:11 nomad consul[1126]:     2017/07/12 17:50:11 [INFO] agent: Synced check '99808528a94be6b0968ec34200b1693571b658cd'
Jul 12 17:50:11 nomad consul[1126]:     2017/07/12 17:50:11 [DEBUG] agent: Node info in sync
Jul 12 17:50:21 nomad consul[1126]:     2017/07/12 17:50:21 [DEBUG] agent: Check '99808528a94be6b0968ec34200b1693571b658cd' is passing
@schmichael
Copy link
Member

Verified and fixing for 0.6. Thanks for the report!

@schmichael schmichael self-assigned this Jul 18, 2017
@schmichael schmichael added this to the v0.6.0 milestone Jul 18, 2017
@marcjay
Copy link
Author

marcjay commented Jul 18, 2017

@schmichael Great, many thanks!

schmichael added a commit that referenced this issue Jul 18, 2017
@schmichael
Never remove unknown agent services
a83d6f9 
Fixes #2827

This is a tradeoff. The pro is that you can run separate client and
server agents on the same node and advertise both. The con is that if a
Nomad agent crashes and isn't restarted on that node in the same mode
its entry will not be cleaned up.

That con scenario seems far less likely to occur than the scenario on
the pro side, and even if we do leak an agent entry the checks will be
failing so nothing should attempt to use it.
@schmichael schmichael mentioned this issue Jul 18, 2017
Merged
@github-actions
Copy link

I'm going to lock this issue because it has been closed for 120 days ⏳. This helps our maintainers find and focus on the active issues.
If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Dec 11, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@schmichael schmichael

Labels
theme/consul type/bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@schmichael @marcjay