Closed Bug 1218006 Opened 9 years ago Closed 8 years ago

Intermittent log parsing error in debug mochitest-other jobs

Categories

(Release Engineering :: General, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: nthomas, Unassigned)

Details

This shows up as dead jobs in the command queue, and when you trace back to the build on the master (eg http://buildbot-master106.bb.releng.scl3.mozilla.com:8201/builders/Rev4%20MacOSX%20Snow%20Leopard%2010.6%20fx-team%20debug%20test%20mochitest-other/builds/665) you find Traceback (most recent call last): File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/twisted/internet/defer.py", line 249, in addCallbacks self._runCallbacks() File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/twisted/internet/defer.py", line 441, in _runCallbacks self.result = callback(self.result, *args, **kw) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/twisted/internet/defer.py", line 318, in callback self._startRunCallbacks(result) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/twisted/internet/defer.py", line 424, in _startRunCallbacks self._runCallbacks() --- <exception caught here> --- File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/twisted/internet/defer.py", line 441, in _runCallbacks self.result = callback(self.result, *args, **kw) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/buildbot-0.8.2_hg_41f0fbee10f4_production_0.8-py2.7.egg/buildbot/process/buildstep.py", line 1074, in <lambda> The tests had been running for 52 minutes at that point d.addCallback(lambda res: self.evaluateCommand(cmd)) # returns results File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/buildbotcustom/steps/base.py", line 14, in evaluateCommand lbs_status = obj.evaluateCommand(self, cmd) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/buildbot-0.8.2_hg_41f0fbee10f4_production_0.8-py2.7.egg/buildbot/process/buildstep.py", line 1172, in evaluateCommand return self.log_eval_func(cmd, self.step_status) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/buildbotcustom/process/factory.py", line 4677, in eval_func regex_status = regex_log_evaluator(cmd, step, global_errors) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/buildbot-0.8.2_hg_41f0fbee10f4_production_0.8-py2.7.egg/buildbot/process/buildstep.py", line 1239, in regex_log_evaluator if err.search(l.getText()): File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/buildbot-0.8.2_hg_41f0fbee10f4_production_0.8-py2.7.egg/buildbot/status/builder.py", line 338, in getText return "".join(self.getChunks([STDOUT, STDERR], onlyText=True)) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/buildbot-0.8.2_hg_41f0fbee10f4_production_0.8-py2.7.egg/buildbot/status/builder.py", line 389, in _generateChunks p.dataReceived(data) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/twisted/protocols/basic.py", line 99, in dataReceived self.doData() File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/twisted/protocols/basic.py", line 62, in doData self.stringReceived(self.__buffer) File "/builds/buildbot/tests1-macosx/lib/python2.7/site-packages/buildbot-0.8.2_hg_41f0fbee10f4_production_0.8-py2.7.egg/buildbot/status/builder.py", line 81, in stringReceived channel = int(line[0]) exceptions.ValueError: invalid literal for int() with base 10: ''
Another one, on linux this time: http://buildbot-master05.build.mozilla.org:8201/builders/Ubuntu%20VM%2012.04%20try%20debug%20test%20mochitest-other/builds/2084 The log has a time jump and ends: 12:37:50 INFO - [8591] WARNING: Trying to spellcheck, but checking seems to be disabled: 'mPendingSpellCheck', file /builds/slave/try-lx-d-000000000000000000000/build/src/extensions/spellcheck/src/mozInlineSpellChecker.cpp, line 908 12:37:50 INFO - [8591] WARNING: Trying to spellcheck, but checking seems to be disabled: 'mPendingSpellCheck', file /builds/slave/try-lx-d-0000000000000000e to READY ... 09:06:01 INFO - Setting pipeline to NULL ... 09:06:01 INFO - Freeing pipeline ... 09:06:03 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 09:06:04 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/firefox', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpMKpGha.mozrunner'; const _SERVER_PORT = '8888'; const
How does the time of these compare to the time when we had a reconfig that removed the mochitest-other job, then a backout and a reconfig which brought it back again?
Jobs ran on bm106 between Start Fri Oct 23 10:01:12 2015 End Fri Oct 23 10:53:39 2015 Elapsed 52 mins, 27 secs Reconfigs at 2015-10-23 09:01:37-0700 [-] configuration update started 2015-10-23 09:06:03-0700 [-] configuration update complete 2015-10-23 10:00:27-0700 [-] configuration update started 2015-10-23 10:00:48-0700 [-] configuration update complete 2015-10-23 12:00:34-0700 [-] configuration update started 2015-10-23 12:00:45-0700 [-] configuration update complete No obvious correlation there.
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → INCOMPLETE
Component: General Automation → General
You need to log in before you can comment on or make changes to this bug.