application error

[corynissen]

This seems to happen about 1 out of 5 times that I try to access the admin page.

[cgansen]

Possibly relevant log statements:

2013-05-23T19:39:47.642314+00:00 app[web.2]: Started GET "/admin/submissions" for 208.54.40.252 at 2013-05-23 19:39:47 +0000
2013-05-23T19:40:03.149722+00:00 app[web.2]: E, [2013-05-23T19:40:03.149510 #2] ERROR -- : worker=0 PID:7 timeout (16s > 15s), killing
2013-05-23T19:40:03.209947+00:00 app[web.2]: E, [2013-05-23T19:40:03.209693 #2] ERROR -- : reaped #<Process::Status: pid 7 SIGKILL (signal 9)> worker=0
2013-05-23T19:40:03.211150+00:00 heroku[router]: at=error code=H13 desc="Connection closed without response" method=GET path=/admin/submissions host=foodborne.smartchicagoapps.org fwd="208.54.40.252" dyno=web.2 connect=10ms service=15720ms status=503 bytes=0
2013-05-23T19:40:03.310317+00:00 app[web.2]: I, [2013-05-23T19:40:03.309893 #139]  INFO -- : worker=0 ready
2013-05-23T19:40:03.410304+00:00 app[web.1]: Started GET "/" for 50.18.57.7 at 2013-05-23 19:40:03 +0000
2013-05-23T19:40:12.002072+00:00 app[web.2]: Started GET "/" for 184.73.237.85 at 2013-05-23 19:40:12 +0000
2013-05-23T19:40:21.365053+00:00 heroku[router]: at=info method=HEAD path=/ host=foodborne.smartchicagoapps.org fwd="184.73.237.85" dyno=web.2 connect=0ms service=9730ms status=200 bytes=0
2013-05-23T19:40:23.760446+00:00 app[web.2]: Started GET "/admin/submissions" for 208.54.40.252 at 2013-05-23 19:40:23 +0000
2013-05-23T19:40:27.796987+00:00 app[web.2]: Started GET "/" for 50.112.95.211 at 2013-05-23 19:40:27 +0000
2013-05-23T19:40:39.313032+00:00 app[web.2]: E, [2013-05-23T19:40:39.301340 #2] ERROR -- : worker=2 PID:16 timeout (16s > 15s), killing
2013-05-23T19:40:39.996772+00:00 heroku[router]: at=error code=H13 desc="Connection closed without response" method=GET path=/admin/submissions host=foodborne.smartchicagoapps.org fwd="208.54.40.252" dyno=web.2 connect=2ms service=16240ms status=503 bytes=0
2013-05-23T19:40:40.010572+00:00 app[web.2]: E, [2013-05-23T19:40:40.010343 #2] ERROR -- : reaped #<Process::Status: pid 16 SIGKILL (signal 9)> worker=2
2013-05-23T19:40:40.109097+00:00 app[web.2]: I, [2013-05-23T19:40:40.103843 #152]  INFO -- : worker=2 ready
2013-05-23T19:40:42.305341+00:00 heroku[router]: at=info method=GET path=/favicon.ico host=foodborne.smartchicagoapps.org fwd="208.54.40.252" dyno=web.1 connect=3ms service=8ms status=200 bytes=1150
2013-05-23T19:40:53.571123+00:00 app[web.1]: Started GET "/" for 204.93.223.151 at 2013-05-23 19:40:53 +0000
2013-05-23T19:40:53.593817+00:00 heroku[router]: at=info method=HEAD path=/ host=foodborne.smartchicagoapps.org fwd="204.93.223.151" dyno=web.1 connect=2ms service=23ms status=200 bytes=0
2013-05-23T19:40:03.490958+00:00 heroku[router]: at=info method=HEAD path=/ host=foodborne.smartchicagoapps.org fwd="50.18.57.7" dyno=web.1 connect=5ms service=80ms status=200 bytes=0
2013-05-23T19:41:56.900970+00:00 app[web.1]: Started GET "/admin/submissions" for 208.54.40.252 at 2013-05-23 19:41:56 +0000
2013-05-23T19:41:57.836835+00:00 heroku[router]: at=info method=GET path=/admin/submissions host=foodborne.smartchicagoapps.org fwd="208.54.40.252" dyno=web.1 connect=7ms service=935ms status=200 bytes=39509

Appears to be timing out and throwing a 503. I have uptime monitoring running via New Relic, and the app seems to experience inexplicable outages, only lasting 30 seconds or so, and then comes right back. Maybe we need to tune the Heroku env, or bump the number of dynos?

[srobbin]

Strange. My guess is that it would've just been a Heroku infrastructure hiccup, but the status site isn't showing any issues.

Cory, has this been happening on other days, or just today? @RaedMan, have you been seen this, too?

[RaedMan]

Yes, all day yesterday. I usually do not log out as admin. I'm on the app everyday without logging in or out and that was the first time in a while I had to log out and back in. I noticed I didn't have problems with any part of the app except for when I clicked on Submissions and it just stalled. When I would refresh is when the error message would show. I was able to get to Tweets and Admin panel without errors, though.

[cgansen]

If it's only on admin/submissions, perhaps there's a DB query or codepath that is taking longer than 15s to execute, and thus triggers a Heroku timeout?

On Thu, May 23, 2013 at 4:08 PM, RaedMan notifications@github.com wrote:

Yes, all day yesterday. I usually do not log out as admin. I'm on the app everyday without logging in or out and that was the first time in a while I had to log out and back in. I noticed I didn't have problems with any part of the app except for when I clicked on Submissions and it just stalled. When I would refresh is when the error message would show. I was able to get to Tweets and Admin panel without errors, though.

— Reply to this email directly or view it on GitHubhttps://github.com/smartchicago/foodborne/issues/33#issuecomment-18371742 .

cgansen@cct.org

[srobbin]

My hack to show the related tweet may be coming back to bite us. I'll take a look.

[corynissen]

Scott: yeah, it's been going on a while. Maybe just on the submissions page, I'm not certain about that though. Usually, a couple of refreshes gets it going again.