Can't deploy the worskop in local

[Kr1Kr1]

Hi,

I read the Autopilot post on the Joyent blog with much interest and tried to reproduce your workshop on a centos vm on aws but I can't make the whole thing run well.
Indeed, I just did a git clone of your repository, docker-compose -f local-compose.yml up -d and tried to reach the different pieces of the demo with more or less luck.

For ex:

• http://my_public_ip:8500 : redirects well on my_public_ip:8500/ui but I get an error message from Consul (HTTP error code from Consul: 404 Not Found)
• http://my_public_ip:4000: ERR_CONNECTION_REFUSED
• http://my_public_ip:3000: ERR_CONNECTION_REFUSED
• http://my_public_ip:80/customers : [{"company":"ACME Corporation","location":"Atlanta","rep":"Alice","source":"[sales:34612fc3a0ce]"},{"company":"Vandelay Industries","location":"Boston","rep":"Bob","source":"[sales:34612fc3a0ce]"},{"company":"Hooli","location":"Chicago","rep":"Carol","source":"[sales:34612fc3a0ce]"},{"company":"Initech","location":"Denver","rep":"Dave","source":"[sales:34612fc3a0ce]"}]
• http://my_public_ip:80/sales: Cannot GET /sales

I must miss something but I don't know what :/
All the inboud and outboud traffic is allowed on this vm.

Thks!
Karin

[tgross]

http://my_public_ip:8500 : redirects well on my_public_ip:8500/ui but I get an error message from Consul (HTTP error code from Consul: 404 Not Found)

This blueprint doesn't have a pinned version of Consul, so it may be that something in the configuration is no longer correct. If you provide the logs from the container we might be able to figure out why.

http://my_public_ip:4000: ERR_CONNECTION_REFUSED
http://my_public_ip:3000: ERR_CONNECTION_REFUSED

That's correct. Those two services have an expose configuration but not a ports configuration -- the services are intentionally not reachable without the Nginx proxy. If you were to docker exec into the containers you should be able to see the results.

http://my_public_ip:80/customers

Ok, LGTM.

http://my_public_ip:80/sales: Cannot GET /sales

Hm, the customers service appears to be able to reach the sales service, based on the JSON response above. If sales weren't registering in Consul, we'd expect that customers wouldn't know about it either. So this suggests that something is going wrong with the Nginx re-configuration. If you provide the logs from the Nginx container we might be able to figure that out too.

[Kr1Kr1]

First of all, many thanks for your very quick reply 🥇

Here are the logs of the consul container:

==> Consul agent running!
         Node name: 'cb0003a1cf37'
        Datacenter: 'dc1'
            Server: true (bootstrap: true)
       Client Addr: 0.0.0.0 (HTTP: 8500, HTTPS: -1, DNS: 53, RPC: 8400)
      Cluster Addr: 172.17.0.2 (LAN: 8301, WAN: 8302)
    Gossip encrypt: false, RPC-TLS: false, TLS-Incoming: false
             Atlas: <disabled>

==> Log data will now stream in as it occurs:

    2017/03/22 00:23:29 [INFO] serf: EventMemberJoin: cb0003a1cf37 172.17.0.2
    2017/03/22 00:23:29 [INFO] serf: EventMemberJoin: cb0003a1cf37.dc1 172.17.0.2
    2017/03/22 00:23:29 [INFO] raft: Node at 172.17.0.2:8300 [Follower] entering Follower state
    2017/03/22 00:23:29 [INFO] consul: adding server cb0003a1cf37 (Addr: 172.17.0.2:8300) (DC: dc1)
    2017/03/22 00:23:29 [INFO] consul: adding server cb0003a1cf37.dc1 (Addr: 172.17.0.2:8300) (DC: dc1)
    2017/03/22 00:23:29 [ERR] agent: failed to sync remote state: No cluster leader
    2017/03/22 00:23:31 [WARN] raft: Heartbeat timeout reached, starting election
    2017/03/22 00:23:31 [INFO] raft: Node at 172.17.0.2:8300 [Candidate] entering Candidate state
    2017/03/22 00:23:31 [INFO] raft: Election won. Tally: 1
    2017/03/22 00:23:31 [INFO] raft: Node at 172.17.0.2:8300 [Leader] entering Leader state
    2017/03/22 00:23:31 [INFO] consul: cluster leadership acquired
    2017/03/22 00:23:31 [INFO] consul: New leader elected: cb0003a1cf37
    2017/03/22 00:23:31 [INFO] raft: Disabling EnableSingleNode (bootstrap)
    2017/03/22 00:23:31 [INFO] consul: member 'cb0003a1cf37' joined, marking health alive
    2017/03/22 00:23:31 [INFO] agent: Synced service 'consul'
    2017/03/22 00:24:12 [ERR] http: Request /v1/agent/check/pass/customers-8ca8e66b8633?note=ok, error: CheckID does not have associated TTL
    2017/03/22 00:24:12 [INFO] agent: Synced service 'customers-8ca8e66b8633'
    2017/03/22 00:24:12 [INFO] agent: Synced check 'customers-8ca8e66b8633'
    2017/03/22 00:24:15 [INFO] agent: Synced check 'customers-8ca8e66b8633'
    2017/03/22 00:24:49 [ERR] http: Request /v1/agent/check/pass/nginx-b972884b9e83?note=ok, error: CheckID does not have associated TTL
    2017/03/22 00:24:49 [INFO] agent: Synced service 'nginx-b972884b9e83'
    2017/03/22 00:24:49 [INFO] agent: Synced check 'nginx-b972884b9e83'
    2017/03/22 00:24:59 [INFO] agent: Synced check 'nginx-b972884b9e83'
    2017/03/22 00:25:00 [ERR] http: Request /v1/agent/check/pass/sales-ef0ccf1d1538?note=ok, error: CheckID does not have associated TTL
    2017/03/22 00:25:00 [INFO] agent: Synced service 'sales-ef0ccf1d1538'
    2017/03/22 00:25:00 [INFO] agent: Synced check 'sales-ef0ccf1d1538'
    2017/03/22 00:25:03 [INFO] agent: Synced check 'sales-ef0ccf1d1538'

I didn't notice that the exposed ports were not binded to the host, my bad.

The logs from the nginx container are :

time="2017-03-22T00:31:29Z" level=debug msg="nginx.health.run waiting for PID 88: " 
time="2017-03-22T00:31:29Z" level=debug msg="nginx.health.run complete" 
time="2017-03-22T00:31:29Z" level=debug msg="nginx.health.RunWithTimeout end" 
time="2017-03-22T00:31:39Z" level=debug msg="nginx.health.RunWithTimeout start" 
time="2017-03-22T00:31:39Z" level=debug msg=nginx.health.Cmd.Start 
time="2017-03-22T00:31:39Z" level=debug msg="nginx.health.run waiting for PID 89: " 
time="2017-03-22T00:31:39Z" level=debug msg="nginx.health.run complete" 
time="2017-03-22T00:31:39Z" level=debug msg="nginx.health.RunWithTimeout end" 
time="2017-03-22T00:31:49Z" level=debug msg="nginx.health.RunWithTimeout start" 
time="2017-03-22T00:31:49Z" level=debug msg=nginx.health.Cmd.Start 
time="2017-03-22T00:31:49Z" level=debug msg="nginx.health.run waiting for PID 90: " 
time="2017-03-22T00:31:49Z" level=debug msg="nginx.health.run complete" 
time="2017-03-22T00:31:49Z" level=debug msg="nginx.health.RunWithTimeout end"

Thank you :)

[tgross]

It looks like Consul is receiving all the service registrations correctly but I don't see any logs there of attempting to access the UI.

For the Nginx logs, what's jumping out at me is that we're not seeing any of the onChange handlers running nor any of the Nginx access logs. Is that the complete log?

[tgross]

Just to double-check, I've just built this blueprint myself and it seems to be working for me. My nginx logs look like this:

$ docker logs workshop_nginx_1
time="2017-03-22T13:32:05Z" level=debug msg="preStart.RunAndWait start"
time="2017-03-22T13:32:05Z" level=debug msg=preStart.Cmd.Run
time="2017-03-22T13:32:05Z" level=info msg="2017/03/22 13:32:05 [ERR] (view) \"service(sales)\" health services: error fetching: Unexpected response code: 500 (No cluster leader)" process=PreStart
time="2017-03-22T13:32:05Z" level=info msg="2017/03/22 13:32:05 [ERR] (runner) watcher reported error: health services: error fetching: Unexpected response code: 500 (No cluster leader)" process=PreStart
time="2017-03-22T13:32:05Z" level=info msg="Consul Template returned errors:" process=PreStart
time="2017-03-22T13:32:05Z" level=debug msg="preStart.RunAndWait end"
time="2017-03-22T13:32:05Z" level=debug msg="nginx.RunAndWait start"
time="2017-03-22T13:32:05Z" level=debug msg=nginx.Cmd.Run
time="2017-03-22T13:32:11Z" level=debug msg="sales.health.RunWithTimeout start"
time="2017-03-22T13:32:11Z" level=debug msg=sales.health.Cmd.Start
time="2017-03-22T13:32:11Z" level=debug msg="sales.health.run waiting for PID 23: "
time="2017-03-22T13:32:11Z" level=debug msg="sales.health.run complete"
time="2017-03-22T13:32:11Z" level=debug msg="sales.health.RunWithTimeout end"
time="2017-03-22T13:32:13Z" level=debug msg="customers.health.RunWithTimeout start"
time="2017-03-22T13:32:13Z" level=debug msg=customers.health.Cmd.Start
time="2017-03-22T13:32:13Z" level=debug msg="customers.health.run waiting for PID 38: "
time="2017-03-22T13:32:13Z" level=debug msg="customers.health.run complete"
time="2017-03-22T13:32:13Z" level=debug msg="customers.health.RunWithTimeout end"
time="2017-03-22T13:32:15Z" level=debug msg="nginx.health.RunWithTimeout start"
time="2017-03-22T13:32:15Z" level=debug msg=nginx.health.Cmd.Start
time="2017-03-22T13:32:15Z" level=debug msg="nginx.health.run waiting for PID 48: "
time="2017-03-22T13:32:15Z" level=debug msg="nginx.health.run complete"
time="2017-03-22T13:32:15Z" level=debug msg="nginx.health.RunWithTimeout end"
time="2017-03-22T13:32:15Z" level=info msg="Unexpected response code: 500 (CheckID does not have associated TTL)\nService not registered, registering..."
time="2017-03-22T13:32:25Z" level=debug msg="nginx.health.RunWithTimeout start"
time="2017-03-22T13:32:25Z" level=debug msg=nginx.health.Cmd.Start
time="2017-03-22T13:32:25Z" level=debug msg="nginx.health.run waiting for PID 49: "
time="2017-03-22T13:32:25Z" level=debug msg="nginx.health.run complete"
time="2017-03-22T13:32:25Z" level=debug msg="nginx.health.RunWithTimeout end"

(Note that the log says customers.health and sales.health because of a minor bug in the log message which was fixed in TritonDataCenter/containerpilot#274, but the log messages are there.)

If I docker exec -it workshop_nginx_1 cat /etc/nginx/nginx.conf then I'll find both the Customers and Sales upstreams are updated as expected. All services appear in the Consul dashboard.