Bug 181907 – Feeder queue has significant delays between iterations

• Component: Tools / Tests
• Status: RESOLVED CONFIGURATION CHANGED

[Aakash Jain]

Feeder queue logs indicate that sometimes it is having ~2hours delays between subsequent iterations. This cause bugs which are cq+ or recently submitted patches not to be submitted to EWS.

https://bugs.webkit.org/show_bug.cgi?id=181896 wasn't picked up by commit-queue because of this.


Sample Logs:


2018-01-19 18:15:50,631 - Feeding commit-queue high priority items [], regular items [331754, 331787]
2018-01-19 18:15:50,631 - Recording work items: [331754, 331787] for commit-queue
2018-01-19 18:15:51,663 - Feeding EWS (32 r? patches, 0 new) 
2018-01-19 20:16:17,680 - Fetching: https://bugs.webkit.org/show_bug.cgi?id=180843&ctype=xml&excludefield=attachmentdata
2018-01-19 20:16:18,061 - Feeding commit-queue high priority items [], regular items []
2018-01-19 20:16:18,061 - Recording work items: [] for commit-queue
2018-01-19 20:16:19,005 - Feeding EWS (32 r? patches, 1 new) 
2018-01-19 20:16:19,005 - Submitting attachment 331829 [details] to EWS queues
2018-01-19 22:17:11,198 - Fetching: https://bugs.webkit.org/show_bug.cgi?id=180843&ctype=xml&excludefield=attachmentdata
2018-01-19 22:17:11,574 - Fetching: https://bugs.webkit.org/show_bug.cgi?id=181804&ctype=xml&excludefield=attachmentdata
2018-01-19 22:17:11,928 - Feeding commit-queue high priority items [], regular items [331827]
2018-01-19 22:17:11,928 - Recording work items: [331827] for commit-queue
2018-01-19 22:17:13,004 - Feeding EWS (32 r? patches, 0 new) 
2018-01-20 00:17:46,461 - Fetching: https://bugs.webkit.org/show_bug.cgi?id=180843&ctype=xml&excludefield=attachmentdata
...
2018-01-20 00:18:25,790 - Recording work items: [331753] for commit-queue
2018-01-20 00:18:26,755 - Feeding EWS (33 r? patches, 0 new)
2018-01-20 02:20:26,859 - CAUTION: feeder-queue will discard all local changes in "/Volumes/Data/Feeder/WebKit"
2018-01-20 02:20:26,859 - Running WebKit feeder-queue.
2018-01-20 02:20:26,859 - Starting Queue
...
2018-01-20 02:30:13,771 - Recording work items: [331798, 331837] for commit-queue
2018-01-20 02:30:14,723 - Feeding EWS (32 r? patches, 0 new)
2018-01-20 04:30:47,981 - Fetching: https://bugs.webkit.org/show_bug.cgi?id=180843&ctype=xml&excludefield=attachmentdata
2018-01-20 04:30:48,370 - Fetching: https://bugs.webkit.org/show_bug.cgi?id=181182&ctype=xml&excludefield=attachmentdata
2018-01-20 04:30:48,739 - Feeding commit-queue high priority items [], regular items [331440]
...
2018-01-20 04:31:25,649 - Feeding commit-queue high priority items [], regular items [331440]
2018-01-20 04:31:25,649 - Recording work items: [331440] for commit-queue
2018-01-20 04:31:28,417 - Feeding EWS (34 r? patches, 0 new)
2018-01-20 06:31:54,747 - Fetching: https://bugs.webkit.org/show_bug.cgi?id=180843&ctype=xml&excludefield=attachmentdata
2018-01-20 06:31:55,119 - Feeding commit-queue high priority items [], regular items []

[Aakash Jain]

It also has this network related exception yesterday:

2018-01-19 17:56:04,580 - Recording work items: [331754] for commit-queue
Traceback (most recent call last):
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/tool/bot/queueengine.py", line 103, in run
    if not self._delegate.process_work_item(work_item):
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/tool/commands/queues.py", line 197, in process_work_item
    feeder.feed()
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/tool/bot/feeders.py", line 62, in feed
    self._tool.status_server.update_work_items(self.queue_name, high_priority_item_ids, item_ids)
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/common/net/statusserver.py", line 156, in update_work_items
    return NetworkTransaction().run(lambda: self._post_work_items_to_server(queue_name, high_priority_work_items, work_items))
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/common/net/networktransaction.py", line 53, in run
    return request()
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/common/net/statusserver.py", line 156, in <lambda>
    return NetworkTransaction().run(lambda: self._post_work_items_to_server(queue_name, high_priority_work_items, work_items))
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/common/net/statusserver.py", line 112, in _post_work_items_to_server
    return self._browser.submit().read()
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/thirdparty/autoinstalled/mechanize/_mechanize.py", line 541, in submit
    return self.open(self.click(*args, **kwds))
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/thirdparty/autoinstalled/mechanize/_mechanize.py", line 203, in open
    return self._mech_open(url, data, timeout=timeout)
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/thirdparty/autoinstalled/mechanize/_mechanize.py", line 230, in _mech_open
    response = UserAgentBase.open(self, request, data)
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/thirdparty/autoinstalled/mechanize/_opener.py", line 193, in open
    response = urlopen(self, req, data)
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/thirdparty/autoinstalled/mechanize/_urllib2_fork.py", line 344, in _open
    '_open', req)
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/thirdparty/autoinstalled/mechanize/_urllib2_fork.py", line 332, in _call_chain
    result = func(*args)
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/thirdparty/autoinstalled/mechanize/_urllib2_fork.py", line 1142, in http_open
    return self.do_open(httplib.HTTPConnection, req)
  File "/Volumes/Data/Feeder/WebKit/Tools/Scripts/webkitpy/thirdparty/autoinstalled/mechanize/_urllib2_fork.py", line 1118, in do_open
    raise URLError(err)
URLError: <urlopen error [Errno 60] Operation timed out>
2018-01-19 17:57:20,013 - Exception while preparing queue Sleeping until 2018-01-19 17:59:20 (120 seconds).

[Aakash Jain]

> 2018-01-19 22:17:13,004 - Feeding EWS (32 r? patches, 0 new) 
> 2018-01-20 00:17:46,461 - Fetching: https://bugs.webkit.org/show_bug.cgi?id=180843&ctype=xml&excludefield=attachmentdata
Notice the 2 hours delay between above two log lines.

[Alexey Proskuryakov]

I updated some settings (notably energy saver). Please check if that helped.

[Aakash Jain]

EWS has been re-implemented from scratch. New EWS does not use feeder-queue. Django ews-app pulls directly from bugzilla.