search

untoldone / bloomapi

Create APIs out of public datasources
https://www.bloomapi.com/documentation/public-data
MIT License
89 stars 29 forks source link

Investigate BloomAPI crash (Sept 26 around 3:14pm PST) #37

Closed untoldone closed 11 years ago

untoldone commented 11 years ago

Offending nginx log error line(s): 2013/09/26 22:14:19 [error] 15697#0: 70675 upstream prematurely closed connection while reading response header from upstream, client: 10.183.251.3, server: localhost, request: "GET /api/search?limit=50&offset=0&key1=npi&op1=eq&value1=TOM HTTP/1.1", upstream: "http://127.0.0.1:3000/api/search?limit=50&offset=0&key1=npi&op1=eq&value1=TOM", host: "www.bloomapi.com" 2013/09/26 22:14:26 [error] 15697#0: 70677 connect() failed (111: Connection refused) while connecting to upstream, client: 10.183.251.3, server: localhost, request: "GET /api/search?limit=50&offset=0&key1=last_name&op1=eq&value1=TOM HTTP/1.1", upstream: "http://127.0.0.1:3000/api/search?limit=50&offset=0&key1=last_name&op1=eq&value1=TOM", host: "www.bloomapi.com"

Access log entries around the same time: 900 10.183.251.3 - - [26/Sep/2013:22:11:04 +0000] "GET /api/npis/1154327559 HTTP/1.1" 200 2037 "-" "-" 901 10.183.251.3 - - [26/Sep/2013:22:11:05 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 902 10.183.251.3 - - [26/Sep/2013:22:11:28 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 903 10.183.251.3 - - [26/Sep/2013:22:11:31 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 904 10.183.251.3 - - [26/Sep/2013:22:12:05 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 905 10.183.251.3 - - [26/Sep/2013:22:12:28 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 906 10.183.251.3 - - [26/Sep/2013:22:12:31 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 907 10.183.251.3 - - [26/Sep/2013:22:13:03 +0000] "GET /api/npis/1124141791 HTTP/1.1" 200 1379 "-" "python-requests/0.13.0" 908 10.183.251.3 - - [26/Sep/2013:22:13:05 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 909 10.183.251.3 - - [26/Sep/2013:22:13:28 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 910 10.183.251.3 - - [26/Sep/2013:22:13:31 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 911 10.183.251.3 - - [26/Sep/2013:22:14:05 +0000] "GET /api/sources HTTP/1.1" 200 170 "-" "Rackspace Monitoring/1.1 (https://monitoring.api.rackspacecloud.com)" 912 10.183.251.3 - - [26/Sep/2013:22:14:19 +0000] "GET /api/search?limit=50&offset=0&key1=npi&op1=eq&value1=TOM HTTP/1.1" 502 181 "-" "-" 913 10.183.251.3 - - [26/Sep/2013:22:14:26 +0000] "GET /api/search?limit=50&offset=0&key1=last_name&op1=eq&value1=TOM HTTP/1.1" 502 181 "-" "-"

There were no error messages in the API's server log.

untoldone commented 11 years ago

Reproduced crash with /api/search?limit=50&offset=0&key1=npi&op1=eq&value1=TOM

There's several issues with this query crashing bloomapi:

untoldone commented 11 years ago

Great post that clarified my misconceptions of nodejs/ expressjs and error handling in callbacks: http://www.asyncdev.net/2013/07/promises-errors-and-express-js/ -- solution here may be slightly more complex to fix properly. I'll fix this as a one off for now, but will need to revisit this issue to protect from other potential uncaught exceptions. (see #40)