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

API Umbrella 0.7 Not Passing Traffic To Back-End #107

Closed
darylrobbins opened this issue Feb 10, 2015 · 17 comments
Closed

API Umbrella 0.7 Not Passing Traffic To Back-End #107

darylrobbins opened this issue Feb 10, 2015 · 17 comments
Labels
bug
Milestone
v0.7.1

Comments

@darylrobbins
Copy link
Contributor

I just setup a fresh instance with API Umbrella 0.7. I have configured my backend servers as I had them before and published the configuration. However, when I try to make a request to the API, I get an Nginx 502 Bad Gateway error. I'll dig into the logs and see where exactly this is happening in the pipeline.
@GUI
Copy link
Member

GUI commented Feb 10, 2015

Hm, if you could take a look or share these log files, that might help pinpoint the issue (but these may contain information on your API backend, so if that is sensitive information, you may want to be careful sharing):

  • /opt/api-umbrella/var/log/router-error.log: This should contain the nginx error explaining the 502 Bad Gateway. This can help pinpoint what's going on.
  • /opt/api-umbrella/var/log/config-reloader.log: This may contain additional debug information if your API Backends aren't properly being published.

@darylrobbins
Copy link
Contributor Author

It smells like it could be an issue with those new DNS improvements you mentioned.

In router-error.log:

2015/02/10 19:21:58 [error] 1848#0: *697 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 10.0.170.1, server: localhost, request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:14013/", host: "10.0.236.9"
2015/02/10 19:33:51 [error] 1845#0: *790 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 10.0.168.21, server: localhost, request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:14013/", host: "10.0.236.9"
2015/02/10 19:44:46 [error] 1845#0: *882 no live upstreams while connecting to upstream, client: 10.0.170.1, server: _, request: "GET /v2/deal/count?token=YMt4iJHUb7x8FlT7a88qJQ HTTP/1.1", upstream: "http://api_umbrella_3abe63d7-508a-4052-8e6e-712242afe722_backend/v2/deal/count?token=YMt4iJHUb7x8FlT7a88qJQ", host: "staging.api.mygrocerydeals.com"
2015/02/10 19:48:28 [error] 1845#0: *910 upstream prematurely closed connection while reading response header from upstream, client: 10.0.170.1, server: localhost, request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:14013/", host: "10.0.236.9"

In config-reloader.log:

{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":50,"host":"staging.api.mygrocerydeals.com","servers":[{"address":"127.255.255.255","down":true}],"msg":"Unexpectedly fetching servers for unknown host - using null route","time":"2015-02-10T18:36:54.201Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.255.255.255:80 down' ]","time":"2015-02-10T18:36:54.202Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":50,"host":"staging.api.mygrocerydeals.com","servers":[{"address":"127.255.255.255","down":true}],"msg":"Unexpectedly fetching servers for unknown host - using null route","time":"2015-02-10T18:36:54.202Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.255.255.255:80 down' ]","time":"2015-02-10T18:36:54.202Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx config written...","time":"2015-02-10T18:36:54.203Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Reloading nginx...","time":"2015-02-10T18:36:54.203Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"stdout":"router-nginx: signal sent\n","stderr":"","msg":"nginx reload signal sent","time":"2015-02-10T18:36:54.336Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Config files written...","time":"2015-02-10T18:36:54.336Z","v":0}

I can curl for staging.api.mygrocerydeals.com from the API proxy host without an issue.

@darylrobbins
Copy link
Contributor Author

From gatekeeper.log:

gatekeeper2.log
62:{"name":"api-umbrella-gatekeeper","hostname":"ip-10-0-236-9","pid":1173,"level":50,"err":{"message":"failed to connect to [127.0.0.1:14001]","name":"Error","stack":"Error: failed to connect to [127.0.0.1:14001]\n    at null.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/server.js:549:74)\n    at emit (events.js:106:17)\n    at null.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/connection_pool.js:150:15)\n    at emit (events.js:98:17)\n    at Socket.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/connection.js:533:10)\n    at Socket.emit (events.js:95:17)\n    at net.js:441:14\n    at process._tickCallback (node.js:442:13)"},"msg":"Gatekeeper worker connections error","time":"2015-02-10T18:19:08.650Z","v":0}
124:{"name":"api-umbrella-gatekeeper","hostname":"ip-10-0-236-9","pid":1511,"level":50,"err":{"message":"failed to connect to [127.0.0.1:14001]","name":"Error","stack":"Error: failed to connect to [127.0.0.1:14001]\n    at null.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/server.js:549:74)\n    at emit (events.js:106:17)\n    at null.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/connection_pool.js:150:15)\n    at emit (events.js:98:17)\n    at Socket.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/connection.js:533:10)\n    at Socket.emit (events.js:95:17)\n    at net.js:441:14\n    at process._tickCallback (node.js:442:13)"},"msg":"Gatekeeper worker connections error","time":"2015-02-10T18:19:46.307Z","v":0}
ack-grep: dnsmasq.log: cannot open file for reading

log-processor.log

2:{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6611,"level":50,"msg":"Request error, retrying -- connect ECONNREFUSED","time":"2015-02-10T16:48:09.662Z","v":0}
110:{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1182,"level":50,"err":{"message":"failed to connect to [127.0.0.1:14001]","name":"Error","stack":"Error: failed to connect to [127.0.0.1:14001]\n    at null.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/server.js:549:74)\n    at emit (events.js:106:17)\n    at null.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/connection_pool.js:150:15)\n    at emit (events.js:98:17)\n    at Socket.<anonymous> (/opt/api-umbrella/embedded/apps/router/shared/node_modules/mongoose/node_modules/mongodb/lib/mongodb/connection/connection.js:533:10)\n    at Socket.emit (events.js:95:17)\n    at net.js:441:14\n    at process._tickCallback (node.js:442:13)"},"msg":"Log processor worker connections error","time":"2015-02-10T18:19:27.972Z","v":0}
112:{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1536,"level":50,"msg":"Request error, retrying -- connect ECONNREFUSED","time":"2015-02-10T18:20:14.285Z","v":0}

@GUI
Copy link
Member

GUI commented Feb 10, 2015

Ah, I think you're likely right that it's related to the DNS changes. What are the contents of the /opt/api-umbrella/var/log/dnsmasq.log file? You'll likely need to use sudo to view the contents of that file.

@darylrobbins
Copy link
Contributor Author

dnsmasq.log:

Feb 10 16:47:58 dnsmasq[6628]: started, version 2.72 cachesize 500
Feb 10 16:47:58 dnsmasq[6628]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth no-DNSSEC loop-detect
Feb 10 16:47:58 dnsmasq[6628]: warning: failed to change owner of /opt/api-umbrella/var/log/dnsmasq.log: Operation not permitted
Feb 10 16:47:58 dnsmasq[6628]: reading /etc/resolv.conf
Feb 10 16:47:58 dnsmasq[6628]: using nameserver 10.0.0.2#53
Feb 10 16:47:58 dnsmasq[6628]: read /etc/hosts - 7 addresses
Feb 10 18:18:23 dnsmasq[1197]: started, version 2.72 cachesize 500
Feb 10 18:18:23 dnsmasq[1197]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth no-DNSSEC loop-detect
Feb 10 18:18:23 dnsmasq[1197]: warning: failed to change owner of /opt/api-umbrella/var/log/dnsmasq.log: Operation not permitted
Feb 10 18:18:23 dnsmasq[1197]: reading /etc/resolv.conf
Feb 10 18:18:23 dnsmasq[1197]: using nameserver 10.0.0.2#53
Feb 10 18:18:23 dnsmasq[1197]: read /etc/hosts - 7 addresses

@darylrobbins
Copy link
Contributor Author

Is there any new mandatory configuration in /etc/api-umbrella/api-umbrella.yml for dnsmasq? I just blew away whatever was in that file and replaced it with my custom config, based on the previous version.

@GUI
Copy link
Member

GUI commented Feb 10, 2015

No additional configuration should be necessary for dnsmasq (and for a bit more context, we added dnsmasq to act as a caching DNS server so we can hammer the DNS server a little more freely, and also act as a cache, since we've seen a number of flakey instances where our DNS servers go down briefly).

Dnsmasq should be pretty transparent (it picks up your current name servers out of /etc/resolv.conf so there's not a ton of configuration for it normally). Can you run these two commands so we can compare the output between what happens by default and what happens via dnsmasq?

$ dig staging.api.mygrocerydeals.com
$ dig @127.0.0.1 -p 14007 staging.api.mygrocerydeals.com

(If you don't have the dig command, you might need to install dnsutils or bind-utils)

Also, what operating system is this on?

Sorry for the trouble, but thanks for reporting this!

@darylrobbins
Copy link
Contributor Author

dig staging.api.mygrocerydeals.com

; <<>> DiG 9.9.5-3ubuntu0.1-Ubuntu <<>> staging.api.mygrocerydeals.com
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 39859
;; flags: qr rd ra; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 4096
;; QUESTION SECTION:
;staging.api.mygrocerydeals.com.    IN  A

;; ANSWER SECTION:
staging.api.mygrocerydeals.com. 300 IN  CNAME   api-staging-us-east.elasticbeanstalk.com.
api-staging-us-east.elasticbeanstalk.com. 60 IN A 54.152.52.186

;; Query time: 80 msec
;; SERVER: 10.0.0.2#53(10.0.0.2)
;; WHEN: Tue Feb 10 20:27:59 UTC 2015
;; MSG SIZE  rcvd: 126

dig @127.0.0.1 -p 14007 staging.api.mygrocerydeals.com

; <<>> DiG 9.9.5-3ubuntu0.1-Ubuntu <<>> @127.0.0.1 -p 14007 staging.api.mygrocerydeals.com
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 36194
;; flags: qr rd ra; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 4096
;; QUESTION SECTION:
;staging.api.mygrocerydeals.com.    IN  A

;; ANSWER SECTION:
staging.api.mygrocerydeals.com. 291 IN  CNAME   api-staging-us-east.elasticbeanstalk.com.
api-staging-us-east.elasticbeanstalk.com. 51 IN A 54.152.52.186

;; Query time: 2 msec
;; SERVER: 127.0.0.1#14007(127.0.0.1)
;; WHEN: Tue Feb 10 20:28:08 UTC 2015
;; MSG SIZE  rcvd: 126

No worries. We're running Ubuntu 14.04.

@GUI
Copy link
Member

GUI commented Feb 10, 2015

Hm, well that's good in the respect that dnsmasq seems to be behaving as expected, but bad in the respect that I don't know what would be causing this then. I'm standing up a fresh Ubuntu 14.04 box that I can do more detailed debugging on later today, but in the meantime, was there more to your config-reloader.log from today? It seems like other error might have happened to explain that output.

Also, I hate to pull an IT Crowd, but have you tried completely restarting API Umbrella (sudo /etc/init.d/api-umbrella restart) since this cropped up?

@darylrobbins
Copy link
Contributor Author

Here is the full config-reload.log:

{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"Worker init","time":"2015-02-10T16:48:03.673Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"Handle startup","time":"2015-02-10T16:48:03.727Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"Write configs","time":"2015-02-10T16:48:03.741Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"Writing nginx config...","time":"2015-02-10T16:48:03.742Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"APIs","time":"2015-02-10T16:48:03.753Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"nginx_servers:  [ '127.0.0.1:14012' ]","time":"2015-02-10T16:48:03.778Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"nginx config written...","time":"2015-02-10T16:48:04.066Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"Reloading nginx...","time":"2015-02-10T16:48:04.067Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"stdout":"router-nginx: signal sent\n","stderr":"","msg":"nginx reload signal sent","time":"2015-02-10T16:48:05.597Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-175-215","pid":6603,"level":30,"msg":"Config files written...","time":"2015-02-10T16:48:05.597Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Worker init","time":"2015-02-10T18:18:28.484Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Handle startup","time":"2015-02-10T18:18:28.512Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Write configs","time":"2015-02-10T18:18:28.524Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Writing nginx config...","time":"2015-02-10T18:18:28.524Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"APIs","time":"2015-02-10T18:18:28.525Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.0.0.1:14012' ]","time":"2015-02-10T18:18:28.551Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx config already up-to-date - skipping...","time":"2015-02-10T18:18:28.750Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Config files written...","time":"2015-02-10T18:18:28.762Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Write configs","time":"2015-02-10T18:23:48.309Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Writing nginx config...","time":"2015-02-10T18:23:48.316Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"apis":[{"_id":"08aad3f0-7b59-43e7-a9f9-1fa02b75f3f8","version":2,"name":"Deals (staging)","sort_order":1,"backend_protocol":"http","frontend_host":"staging.api.mgd.io","backend_host":"staging.api.mygrocerydeals.com","balance_algorithm":"least_conn","updated_by":"514714c0-54da-4668-98c4-3e9adec178d6","updated_at":"2015-02-10T18:23:41.364Z","created_at":"2015-02-10T18:22:19.744Z","created_by":"514714c0-54da-4668-98c4-3e9adec178d6","settings":{"require_https":null,"disable_api_key":null,"rate_limit_mode":null,"error_templates":{},"error_data":{},"_id":"13617487-92aa-45a5-8df4-e4a0ef369528","append_query_string":"token=YMt4iJHUb7x8FlT7a88qJQ"},"servers":[{"host":"staging.api.mygrocerydeals.com","port":80,"_id":"ebae3b37-b52c-4b33-a942-c9576683d23f"}],"url_matches":[{"frontend_prefix":"/v2/","backend_prefix":"/v2/","_id":"ca463a5d-7c92-4d35-8d4e-c2910d17b5d1"}]}],"msg":"APIs","time":"2015-02-10T18:23:48.318Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.0.0.1:14012' ]","time":"2015-02-10T18:23:48.319Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":50,"host":"staging.api.mygrocerydeals.com","servers":[{"address":"127.255.255.255","down":true}],"msg":"Unexpectedly fetching servers for unknown host - using null route","time":"2015-02-10T18:23:48.321Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.255.255.255:80 down' ]","time":"2015-02-10T18:23:48.322Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx config written...","time":"2015-02-10T18:23:48.328Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Reloading nginx...","time":"2015-02-10T18:23:48.329Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"stdout":"router-nginx: signal sent\n","stderr":"","msg":"nginx reload signal sent","time":"2015-02-10T18:23:48.572Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Config files written...","time":"2015-02-10T18:23:48.572Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Write configs","time":"2015-02-10T18:32:01.715Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Writing nginx config...","time":"2015-02-10T18:32:01.717Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"apis":[{"_id":"08aad3f0-7b59-43e7-a9f9-1fa02b75f3f8","version":3,"name":"Deals (test)","sort_order":1,"backend_protocol":"http","frontend_host":"test.api.mgd.io","backend_host":"staging.api.mygrocerydeals.com","balance_algorithm":"least_conn","updated_by":"514714c0-54da-4668-98c4-3e9adec178d6","updated_at":"2015-02-10T18:31:52.264Z","created_at":"2015-02-10T18:22:19.744Z","created_by":"514714c0-54da-4668-98c4-3e9adec178d6","settings":{"require_https":null,"disable_api_key":null,"rate_limit_mode":null,"error_templates":{},"error_data":{},"_id":"13617487-92aa-45a5-8df4-e4a0ef369528","append_query_string":"token=YMt4iJHUb7x8FlT7a88qJQ"},"servers":[{"host":"staging.api.mygrocerydeals.com","port":80,"_id":"ebae3b37-b52c-4b33-a942-c9576683d23f"}],"url_matches":[{"frontend_prefix":"/v2/","backend_prefix":"/v2/","_id":"ca463a5d-7c92-4d35-8d4e-c2910d17b5d1"}]}],"msg":"APIs","time":"2015-02-10T18:32:01.718Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.0.0.1:14012' ]","time":"2015-02-10T18:32:01.718Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":50,"host":"staging.api.mygrocerydeals.com","servers":[{"address":"127.255.255.255","down":true}],"msg":"Unexpectedly fetching servers for unknown host - using null route","time":"2015-02-10T18:32:01.719Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.255.255.255:80 down' ]","time":"2015-02-10T18:32:01.719Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx config written...","time":"2015-02-10T18:32:01.720Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Reloading nginx...","time":"2015-02-10T18:32:01.721Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"stdout":"router-nginx: signal sent\n","stderr":"","msg":"nginx reload signal sent","time":"2015-02-10T18:32:01.863Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Config files written...","time":"2015-02-10T18:32:01.863Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Write configs","time":"2015-02-10T18:36:54.199Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Writing nginx config...","time":"2015-02-10T18:36:54.199Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"apis":[{"_id":"08aad3f0-7b59-43e7-a9f9-1fa02b75f3f8","version":3,"name":"Deals (test)","sort_order":1,"backend_protocol":"http","frontend_host":"test.api.mgd.io","backend_host":"staging.api.mygrocerydeals.com","balance_algorithm":"least_conn","updated_by":"514714c0-54da-4668-98c4-3e9adec178d6","updated_at":"2015-02-10T18:31:52.264Z","created_at":"2015-02-10T18:22:19.744Z","created_by":"514714c0-54da-4668-98c4-3e9adec178d6","settings":{"require_https":null,"disable_api_key":null,"rate_limit_mode":null,"error_templates":{},"error_data":{},"_id":"13617487-92aa-45a5-8df4-e4a0ef369528","append_query_string":"token=YMt4iJHUb7x8FlT7a88qJQ"},"servers":[{"host":"staging.api.mygrocerydeals.com","port":80,"_id":"ebae3b37-b52c-4b33-a942-c9576683d23f"}],"url_matches":[{"frontend_prefix":"/v2/","backend_prefix":"/v2/","_id":"ca463a5d-7c92-4d35-8d4e-c2910d17b5d1"}]},{"_id":"3abe63d7-508a-4052-8e6e-712242afe722","version":2,"name":"Deals (Production)","sort_order":2,"backend_protocol":"http","frontend_host":"api.mgd.io","backend_host":"staging.api.mygrocerydeals.com","balance_algorithm":"least_conn","updated_by":"514714c0-54da-4668-98c4-3e9adec178d6","updated_at":"2015-02-10T18:36:45.847Z","created_at":"2015-02-10T18:35:58.967Z","created_by":"514714c0-54da-4668-98c4-3e9adec178d6","settings":{"require_https":null,"disable_api_key":null,"rate_limit_mode":null,"error_templates":{},"error_data":{},"_id":"c734daae-0cd7-4154-839f-c7423da1433c","append_query_string":"token=YMt4iJHUb7x8FlT7a88qJQ"},"servers":[{"host":"staging.api.mygrocerydeals.com","port":80,"_id":"a6036022-3b6b-4260-9372-5607f7745e29"}],"url_matches":[{"frontend_prefix":"/v2/","backend_prefix":"/v2/","_id":"c7ca0da9-d81f-4b6c-835d-f8bf60a711d3"}]}],"msg":"APIs","time":"2015-02-10T18:36:54.200Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.0.0.1:14012' ]","time":"2015-02-10T18:36:54.201Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":50,"host":"staging.api.mygrocerydeals.com","servers":[{"address":"127.255.255.255","down":true}],"msg":"Unexpectedly fetching servers for unknown host - using null route","time":"2015-02-10T18:36:54.201Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.255.255.255:80 down' ]","time":"2015-02-10T18:36:54.202Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":50,"host":"staging.api.mygrocerydeals.com","servers":[{"address":"127.255.255.255","down":true}],"msg":"Unexpectedly fetching servers for unknown host - using null route","time":"2015-02-10T18:36:54.202Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx_servers:  [ '127.255.255.255:80 down' ]","time":"2015-02-10T18:36:54.202Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"nginx config written...","time":"2015-02-10T18:36:54.203Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Reloading nginx...","time":"2015-02-10T18:36:54.203Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"stdout":"router-nginx: signal sent\n","stderr":"","msg":"nginx reload signal sent","time":"2015-02-10T18:36:54.336Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":1177,"level":30,"msg":"Config files written...","time":"2015-02-10T18:36:54.336Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Worker init","time":"2015-02-10T20:45:14.250Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Handle startup","time":"2015-02-10T20:45:14.334Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Write configs","time":"2015-02-10T20:45:14.335Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Writing nginx config...","time":"2015-02-10T20:45:14.335Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"APIs","time":"2015-02-10T20:45:14.335Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"nginx_servers:  [ '127.0.0.1:14012' ]","time":"2015-02-10T20:45:14.349Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"nginx config written...","time":"2015-02-10T20:45:14.546Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Reloading nginx...","time":"2015-02-10T20:45:14.546Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"stdout":"router-nginx: signal sent\n","stderr":"","msg":"nginx reload signal sent","time":"2015-02-10T20:45:15.376Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Config files written...","time":"2015-02-10T20:45:15.377Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Write configs","time":"2015-02-10T20:45:32.427Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Writing nginx config...","time":"2015-02-10T20:45:32.427Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"apis":[{"_id":"08aad3f0-7b59-43e7-a9f9-1fa02b75f3f8","version":3,"name":"Deals (test)","sort_order":1,"backend_protocol":"http","frontend_host":"test.api.mgd.io","backend_host":"staging.api.mygrocerydeals.com","balance_algorithm":"least_conn","updated_by":"514714c0-54da-4668-98c4-3e9adec178d6","updated_at":"2015-02-10T18:31:52.264Z","created_at":"2015-02-10T18:22:19.744Z","created_by":"514714c0-54da-4668-98c4-3e9adec178d6","settings":{"require_https":null,"disable_api_key":null,"rate_limit_mode":null,"error_templates":{},"error_data":{},"_id":"13617487-92aa-45a5-8df4-e4a0ef369528","append_query_string":"token=YMt4iJHUb7x8FlT7a88qJQ"},"servers":[{"host":"staging.api.mygrocerydeals.com","port":80,"_id":"ebae3b37-b52c-4b33-a942-c9576683d23f"}],"url_matches":[{"frontend_prefix":"/v2/","backend_prefix":"/v2/","_id":"ca463a5d-7c92-4d35-8d4e-c2910d17b5d1"}]},{"_id":"3abe63d7-508a-4052-8e6e-712242afe722","version":2,"name":"Deals (Production)","sort_order":2,"backend_protocol":"http","frontend_host":"api.mgd.io","backend_host":"staging.api.mygrocerydeals.com","balance_algorithm":"least_conn","updated_by":"514714c0-54da-4668-98c4-3e9adec178d6","updated_at":"2015-02-10T18:36:45.847Z","created_at":"2015-02-10T18:35:58.967Z","created_by":"514714c0-54da-4668-98c4-3e9adec178d6","settings":{"require_https":null,"disable_api_key":null,"rate_limit_mode":null,"error_templates":{},"error_data":{},"_id":"c734daae-0cd7-4154-839f-c7423da1433c","append_query_string":"token=YMt4iJHUb7x8FlT7a88qJQ"},"servers":[{"host":"staging.api.mygrocerydeals.com","port":80,"_id":"a6036022-3b6b-4260-9372-5607f7745e29"}],"url_matches":[{"frontend_prefix":"/v2/","backend_prefix":"/v2/","_id":"c7ca0da9-d81f-4b6c-835d-f8bf60a711d3"}]}],"msg":"APIs","time":"2015-02-10T20:45:32.428Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"nginx_servers:  [ '127.0.0.1:14012' ]","time":"2015-02-10T20:45:32.430Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":50,"host":"staging.api.mygrocerydeals.com","servers":[{"address":"127.255.255.255","down":true}],"msg":"Unexpectedly fetching servers for unknown host - using null route","time":"2015-02-10T20:45:32.430Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"nginx_servers:  [ '127.255.255.255:80 down' ]","time":"2015-02-10T20:45:32.431Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":50,"host":"staging.api.mygrocerydeals.com","servers":[{"address":"127.255.255.255","down":true}],"msg":"Unexpectedly fetching servers for unknown host - using null route","time":"2015-02-10T20:45:32.432Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"nginx_servers:  [ '127.255.255.255:80 down' ]","time":"2015-02-10T20:45:32.439Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"nginx config written...","time":"2015-02-10T20:45:32.444Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Reloading nginx...","time":"2015-02-10T20:45:32.445Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"stdout":"router-nginx: signal sent\n","stderr":"","msg":"nginx reload signal sent","time":"2015-02-10T20:45:32.885Z","v":0}
{"name":"api-umbrella-router","hostname":"ip-10-0-236-9","pid":3748,"level":30,"msg":"Config files written...","time":"2015-02-10T20:45:32.885Z","v":0}

@darylrobbins
Copy link
Contributor Author

Oh, and restarting had no effect.

Here is the packer script I used to build the machine image:

{
  "variables": {
    "api_umbrella_url": "https://developer.nrel.gov/downloads/api-umbrella/ubuntu/14.04/api-umbrella_0.7.0-1_amd64.deb"
  },
  "builders": [
    {
      "type": "amazon-ebs",
      "region": "us-east-1",
      "source_ami": "ami-9a562df2",
      "instance_type": "t2.small",
      "ssh_username": "ubuntu",
      "ssh_private_ip": true,
      "associate_public_ip_address": true,
      "vpc_id": "<insert-vpc-id>",
      "subnet_id": "<insert-subnet-id>",
      "ami_name": "api-umbrella 0.7 {{timestamp}}",
      "ami_description": "API Umbrella 0.7 Proxy Server"
    }
  ],
  "provisioners": [
    {
      "type": "file",
      "source": "api-umbrella.yml",
      "destination": "/tmp/api-umbrella.yml"
    },
    {
      "type": "shell",
      "inline": [
        "echo *** Upgrade packages and install dependencies",
        "sudo apt-get update",
        "sudo apt-get upgrade -y",
        "sudo apt-get install -y gcc curl"
      ]
    },
    {
      "type": "shell",
      "inline": [
        "echo *** Install API-Umbrella",
        "curl -o /tmp/api-umbrella.deb {{user `api_umbrella_url`}}",
        "sudo dpkg -i /tmp/api-umbrella.deb",
        "sudo cp /tmp/api-umbrella.yml /etc/api-umbrella/api-umbrella.yml",
        "sudo chown api-umbrella:api-umbrella /etc/api-umbrella/api-umbrella.yml",
        "sudo /etc/init.d/api-umbrella start"
      ]
    }
  ]
}

And my config file:

web:
  admin:
    initial_superusers:
      - <my email here>

@darylrobbins
Copy link
Contributor Author

@GUI, I can grant you ssh access to the box if it would help to troubleshoot the issue. If so, I'll need your SSH public key and the public IP address you'd be connecting from. You have my email from the message I sent you a week or so ago.

@GUI
Copy link
Member

GUI commented Feb 10, 2015

Thanks for the offer. I was actually able to replicate this issue on a local Ubuntu 14.04 box with your same config, so that definitely simplifies things. I haven't had a chance to debug it yet, but I should be able to look at it a bit later today. Now that I can replicate it locally, I'm hoping it should be fairly straight forward.

@GUI
Copy link
Member

GUI commented Feb 11, 2015

I believe I've pinpointed the issue, and apologies for releasing v0.7 like this. As a very short term work around, can you try running this after starting up API Umbrella?

$ sudo /opt/api-umbrella/embedded/bin/supervisorctl -c /opt/api-umbrella/etc/supervisord.conf restart config-reloader

Does that make things work for you?

In my tests that restart command fixes things for me. However, in my tests rebooting API Umbrella also fixes this issue, so I'm seeing slightly different behavior. But I think this same bug might lead to a race condition on startup, so that could also explain why your system has remained broken across restarts (I've just gotten lucky on my reboots, and you've gotten unlucky).

If that restart config-reloader command above works, though, then I think I can prepare a v0.7.1 release sometime tomorrow to get this fixed pronto.

@darylrobbins
Copy link
Contributor Author

The restart config-reloader does work for me. After running it, I am able to hit the API.

I think this just serves as another argument for the new architecture. It's extremely difficult to thoroughly test an open source project with so many moving parts. You've done a masterful job of hiding the complexity under the hood -- sometimes almost too good of a job -- but you just can't avoid all the places there are for gremlins to hide. :)

@GUI GUI added this to the v0.7.1 milestone Feb 12, 2015
@GUI
Copy link
Member

GUI commented Feb 12, 2015

Thanks for reporting this and your help debugging this. I believe this should now be fixed in the new v0.7.1 packages that have been released. I've also added better integration tests surrounding this.

If you want to give the new packages a spin, hopefully they'll do the trick. Sorry for the trouble! (And yes, I agree the new architecture would help simplify many things--the good news is that the rearchitecture seems to be coming together quite nicely in a fully backwards compatible way. We're still a ways off, but I think it's all quite promising.)

@GUI GUI closed this as completed Feb 12, 2015
@GUI GUI added the bug label Feb 12, 2015
@darylrobbins
Copy link
Contributor Author

Fix confirmed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
v0.7.1
Development

No branches or pull requests
2 participants
@GUI @darylrobbins