RESOLVED FIXED 107184
HTTP 500 error between QueueStatusServer and bot(s) 
https://bugs.webkit.org/show_bug.cgi?id=107184
Summary HTTP 500 error between QueueStatusServer and bot(s)
Alan Cutter
Reported 2013-01-17 14:57:43 PST
The feeder queue is frequently blocked for over 8 minutes at a time. feeder-queue logs: > Feeding commit-queue items [182076, 183087] > Feeding EWS (551 r? patches, 14 new) > Submitting attachment 124896 [details] to EWS queues > Submitting attachment 183107 [details] to EWS queues > Submitting attachment 179684 [details] to EWS queues > Submitting attachment 183109 [details] to EWS queues > Submitting attachment 158695 [details] to EWS queues > Submitting attachment 120296 [details] to EWS queues > Submitting attachment 182256 [details] to EWS queues > Submitting attachment 157608 [details] to EWS queues > Submitting attachment 179699 [details] to EWS queues > Submitting attachment 177748 [details] to EWS queues > Submitting attachment 158718 [details] to EWS queues > Submitting attachment 167385 [details] to EWS queues > Received HTTP status 500 loading "None". Retrying in 10 seconds... > Received HTTP status 500 loading "None". Retrying in 15.0 seconds... > Received HTTP status 500 loading "None". Retrying in 22.5 seconds... > Received HTTP status 500 loading "None". Retrying in 33.75 seconds... > Received HTTP status 500 loading "None". Retrying in 50.625 seconds... > Received HTTP status 500 loading "None". Retrying in 75.9375 seconds... > Received HTTP status 500 loading "None". Retrying in 113.90625 seconds... > Received HTTP status 500 loading "None". Retrying in 170.859375 seconds... > Traceback (most recent call last): > File "/mnt/git/webkit-feeder-queue/Tools/Scripts/webkitpy/tool/bot/queueengine.py", line 105, in run > if not self._delegate.process_work_item(work_item): > File "/mnt/git/webkit-feeder-queue/Tools/Scripts/webkitpy/tool/commands/queues.py", line 196, in process_work_item > feeder.feed() > File "/mnt/git/webkit-feeder-queue/Tools/Scripts/webkitpy/tool/bot/feeders.py", line 97, in feed > self._tool.status_server.submit_to_ews(attachment_id) > File "/mnt/git/webkit-feeder-queue/Tools/Scripts/webkitpy/common/net/statusserver.py", line 123, in submit_to_ews > return NetworkTransaction().run(lambda: self._post_work_item_to_ews(attachment_id)) > File "/mnt/git/webkit-feeder-queue/Tools/Scripts/webkitpy/common/net/networktransaction.py", line 57, in run > self._check_for_timeout() > File "/mnt/git/webkit-feeder-queue/Tools/Scripts/webkitpy/common/net/networktransaction.py", line 63, in _check_for_timeout > raise NetworkTimeout() > NetworkTimeout: NetworkTimeout > Exception while preparing queue Sleeping until 2013-01-17 04:52:19 (2 mins). The QueueStatusServer frequently throws HTTP 500 errors. QSS logs: Recent errors: > 2013-01-16 21:21:35.024 /submit-to-ews 500 750ms 2kb Python-urllib/2.6 > E 2013-01-16 21:21:35.017 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:18:43.200 /submit-to-ews 500 517ms 2kb Python-urllib/2.6 > E 2013-01-16 21:18:43.197 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:16:48.409 /submit-to-ews 500 416ms 2kb Python-urllib/2.6 > E 2013-01-16 21:16:48.394 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:15:31.652 /submit-to-ews 500 493ms 2kb Python-urllib/2.6 > E 2013-01-16 21:15:31.650 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:14:40.224 /submit-to-ews 500 1150ms 2kb Python-urllib/2.6 > E 2013-01-16 21:14:40.218 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:14:04.705 /submit-to-ews 500 327ms 2kb Python-urllib/2.6 > E 2013-01-16 21:14:04.703 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:13:41.396 /submit-to-ews 500 464ms 2kb Python-urllib/2.6 > E 2013-01-16 21:13:41.394 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:13:25.793 /submit-to-ews 500 327ms 2kb Python-urllib/2.6 > E 2013-01-16 21:13:25.790 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:13:15.324 /submit-to-ews 500 391ms 2kb Python-urllib/2.6 > E 2013-01-16 21:13:15.322 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:11:09.632 /submit-to-ews 500 1127ms 2kb Python-urllib/2.6 > E 2013-01-16 21:11:09.619 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:08:17.301 /submit-to-ews 500 853ms 2kb Python-urllib/2.6 > E 2013-01-16 21:08:17.299 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:06:22.207 /submit-to-ews 500 347ms 2kb Python-urllib/2.6 > E 2013-01-16 21:06:22.205 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:05:05.513 /submit-to-ews 500 512ms 2kb Python-urllib/2.6 > E 2013-01-16 21:05:05.512 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:04:13.935 /submit-to-ews 500 312ms 2kb Python-urllib/2.6 > E 2013-01-16 21:04:13.933 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:03:39.489 /submit-to-ews 500 708ms 2kb Python-urllib/2.6 > E 2013-01-16 21:03:39.487 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib > 2013-01-16 21:03:16.167 /submit-to-ews 500 717ms 2kb Python-urllib/2.6 > E 2013-01-16 21:03:16.159 Values may not be more than 1000000 bytes in length; received 1054167 bytes Traceback (most recent call last): File "/base/python_runtime/python_lib Single error detail: > 2013-01-16 21:15:31.652 /submit-to-ews 500 493ms 2kb Python-urllib/2.6 > 8.34.213.203 - - [16/Jan/2013:21:15:31 -0800] "POST /submit-to-ews HTTP/1.1" 500 2132 "http://queues.webkit.org/submit-to-ews" "Python-urllib/2.6" "queues.webkit.org" ms=493 cpu_ms=107 cpm_usd=0.000238 instance=00c61b117c8dc6bb676ce419546a20bc69ae89 > E 2013-01-16 21:15:31.650 > Values may not be more than 1000000 bytes in length; received 1054167 bytes > Traceback (most recent call last): > File "/base/python_runtime/python_lib/versions/1/google/appengine/ext/webapp/_webapp25.py", line 716, in __call__ > handler.post(*groups) > File "/base/data/home/apps/webkit-commit-queue/1.364503684603662849/handlers/submittoews.py", line 64, in post > self._add_attachment_to_ews_queues(attachment) > File "/base/data/home/apps/webkit-commit-queue/1.364503684603662849/handlers/submittoews.py", line 58, in _add_attachment_to_ews_queues > if self._should_add_to_ews_queue(queue, attachment): > File "/base/data/home/apps/webkit-commit-queue/1.364503684603662849/handlers/submittoews.py", line 46, in _should_add_to_ews_queue > latest_status = attachment.status_for_queue(queue) > File "/base/data/home/apps/webkit-commit-queue/1.364503684603662849/model/attachment.py", line 95, in status_for_queue > queue_summary = self.summary().get(queue.name_with_underscores()) > File "/base/data/home/apps/webkit-commit-queue/1.364503684603662849/model/attachment.py", line 73, in summary > memcache.set(str(self.id), self._summary, namespace="attachment-summary") > File "/base/python_runtime/python_lib/versions/1/google/appengine/api/memcache/__init__.py", line 793, in set > namespace=namespace) > File "/base/python_runtime/python_lib/versions/1/google/appengine/api/memcache/__init__.py", line 898, in _set_with_policy > time, '', namespace) > File "/base/python_runtime/python_lib/versions/1/google/appengine/api/memcache/__init__.py", line 977, in _set_multi_async_with_policy > stored_value, flags = _validate_encode_value(value, self._do_pickle) > File "/base/python_runtime/python_lib/versions/1/google/appengine/api/memcache/__init__.py", line 236, in _validate_encode_value > 'received %d bytes' % (MAX_VALUE_SIZE, len(stored_value))) > ValueError: Values may not be more than 1000000 bytes in length; received 1054167 bytes These are probably related and may account for the unusual consistently spiky requests/s graph in App Engine.
Attachments
Patch (2.09 KB, patch)
2013-01-24 22:02 PST, Alan Cutter 		no flags
DetailsFormatted DiffDiff
Patch (2.88 KB, patch)
2013-01-24 22:11 PST, Alan Cutter 		no flags
DetailsFormatted DiffDiff
Show Obsolete (1) View All Add attachment proposed patch, testcase, etc.
Adam Barth
Comment 1 2013-01-17 16:14:23 PST
Which value is getting too big? We've seen this in the past when there's a queue that hasn't been processing for a long time and has lots of work to do...
Philip Rogers
Comment 2 2013-01-19 18:55:06 PST
*** Bug 107388 has been marked as a duplicate of this bug. ***
Alan Cutter
Comment 3 2013-01-24 22:02:57 PST
Created attachment 184662 [details] Patch
Alan Cutter
Comment 4 2013-01-24 22:05:47 PST
(In reply to comment #3) > Created an attachment (id=184662) [details] > Patch Patch removes the use of memcache from the Attachment class.
Adam Barth
Comment 5 2013-01-24 22:05:49 PST
Comment on attachment 184662 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=184662&action=review > Tools/QueueStatusServer/model/attachment.py:-41 > - def dirty(cls, attachment_id): > - memcache.delete(str(attachment_id), namespace="attachment-summary") Don't we need to remove the caller of this function in updatestate.py?
Alan Cutter
Comment 6 2013-01-24 22:11:26 PST
Created attachment 184664 [details] Patch
Alan Cutter
Comment 7 2013-01-24 22:12:21 PST
(In reply to comment #5) > (From update of attachment 184662 [details]) > View in context: https://bugs.webkit.org/attachment.cgi?id=184662&action=review > > > Tools/QueueStatusServer/model/attachment.py:-41 > > - def dirty(cls, attachment_id): > > - memcache.delete(str(attachment_id), namespace="attachment-summary") > > Don't we need to remove the caller of this function in updatestate.py? Thanks for catching that, removed all calls to Attachment.dirty().
Eric Seidel (no email)
Comment 8 2013-01-24 22:53:15 PST
Comment on attachment 184664 [details] Patch This is OK. Presumably we'll have to implement a replacement for what we were attempting to cache. :)
WebKit Review Bot
Comment 9 2013-01-24 22:56:40 PST
Comment on attachment 184664 [details] Patch Rejecting attachment 184664 [details] from commit-queue. Failed to run "['/mnt/git/webkit-commit-queue/Tools/Scripts/webkit-patch', '--status-host=queues.webkit.org', '--bot-id=gce-cq-02', 'apply-attachment', '--no-update', '--non-interactive', 184664, '--port=chromium-xvfb']" exit_code: 2 cwd: /mnt/git/webkit-commit-queue Last 500 characters of output: ply', '--force', '--reviewer', 'Adam Barth']" exit_code: 2 cwd: /mnt/git/webkit-commit-queue Parsed 3 diffs from patch file(s). patch: **** Can't create file /tmp/ppCBCh5i : No space left on device patch: **** Can't create file /tmp/ppBG1Tdm : No space left on device patch: **** Can't create file /tmp/ppMfF0Ml : No space left on device Failed to run "[u'/mnt/git/webkit-commit-queue/Tools/Scripts/svn-apply', '--force', '--reviewer', 'Adam Barth']" exit_code: 2 cwd: /mnt/git/webkit-commit-queue Full output: http://queues.webkit.org/results/16120144
Adam Barth
Comment 10 2013-01-24 23:01:31 PST
Comment on attachment 184664 [details] Patch Clearing flags on attachment: 184664 Committed r140786: <http://trac.webkit.org/changeset/140786>
Adam Barth
Comment 11 2013-01-24 23:01:35 PST
All reviewed patches have been landed. Closing bug.
Alan Cutter
Comment 12 2013-01-30 21:19:42 PST
*** Bug 75024 has been marked as a duplicate of this bug. ***
Note You need to log in before you can comment on or make changes to this bug.