Closed Bug 966133 Opened 10 years ago Closed 9 years ago

Intermittent talosError: Timeout in tp5n [browser_output.txt]

Categories

(Testing :: Talos, defect)

Product:
Testing
Component:
Talos
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED WORKSFORME

People

(Reporter: KWierso, Unassigned)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

output the harness name as an error message (1.0)
823 bytes, patch
dminor
: review+
philor
: feedback+
Details | Diff | Splinter Review 
https://tbpl.mozilla.org/php/getParsedLog.php?id=33843450&tree=Mozilla-Inbound
slave: talos-r4-snow-085




16:44:46     INFO -  JavaScript error: http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html, line 410: syntax error
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129044431 68.167732
16:44:46     INFO -  __WARNTimeout (14/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html__WARN
16:44:46     INFO -  RSS: Main: 192266240
16:44:46     INFO -  JavaScript error: http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html, line 410: syntax error
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129049681 48.809545
16:44:46     INFO -  __WARNTimeout (15/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html__WARN
16:44:46     INFO -  RSS: Main: 191803392
16:44:46     INFO -  JavaScript error: http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html, line 410: syntax error
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129054932 78.665494
16:44:46     INFO -  Warning: attempting to collect counter Main_RSS and it is not registered
16:44:46     INFO -  __WARNTimeout (16/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html__WARN
16:44:46     INFO -  RSS: Main: 192942080
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129060104 23.990789
16:44:46     INFO -  JavaScript error: http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html, line 410: syntax error
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129060180 53.789713
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129064980 27.210263
16:44:46     INFO -  __WARNTimeout (17/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html__WARN
16:44:46     INFO -  RSS: Main: 192974848
16:44:46     INFO -  JavaScript error: http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html, line 410: syntax error
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129065445 55.086014
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129067116 21.417972
16:44:46     INFO -  __WARNTimeout (18/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html__WARN
16:44:46     INFO -  RSS: Main: 195235840
16:44:46     INFO -  JavaScript error: http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html, line 410: syntax error
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129070680 70.998751
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129071259 28.049292
16:44:46     INFO -  __WARNTimeout (19/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html__WARN
16:44:46     INFO -  RSS: Main: 193638400
16:44:46     INFO -  JavaScript error: http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html, line 410: syntax error
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129075940 56.189304
16:44:46     INFO -  Warning: attempting to collect counter Main_RSS and it is not registered
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129077295 24.420337
16:44:46     INFO -  __FAILTimeout (20/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html__FAIL
16:44:46     INFO -  RSS: Main: 192880640
16:44:46     INFO -  MOZ_EVENT_TRACE sample 1391129080924 75.717662
16:44:46     INFO -  MOZ_EVENT_TRACE stop 1391129080934
16:44:46     INFO -  ###!!! [Child][DispatchAsyncMessage] Error: Route error: message sent to unknown actor ID
16:44:46     INFO -  Failed tp5o:
16:44:46     INFO -  		Stopped Thu, 30 Jan 2014 16:44:46
16:44:46    ERROR -  Traceback (most recent call last):
16:44:46     INFO -    File "/builds/slave/talos-slave/test/build/venv/lib/python2.7/site-packages/talos/run_tests.py", line 329, in run_tests
16:44:46     INFO -      talos_results.add(mytest.runTest(browser_config, test))
16:44:46     INFO -    File "/builds/slave/talos-slave/test/build/venv/lib/python2.7/site-packages/talos/ttest.py", line 421, in runTest
16:44:46     INFO -      test_results.add(browser_log_filename, counter_results=self.counter_results)
16:44:46     INFO -    File "/builds/slave/talos-slave/test/build/venv/lib/python2.7/site-packages/talos/results.py", line 128, in add
16:44:46     INFO -      browserLog = BrowserLogResults(filename=results, counter_results=counter_results, global_counters=self.global_counters)
16:44:46     INFO -    File "/builds/slave/talos-slave/test/build/venv/lib/python2.7/site-packages/talos/results.py", line 322, in __init__
16:44:46     INFO -      self.error(match.group(1))
16:44:46     INFO -    File "/builds/slave/talos-slave/test/build/venv/lib/python2.7/site-packages/talos/results.py", line 337, in error
16:44:46 CRITICAL -      raise utils.talosError(message)
16:44:46 CRITICAL -  talosError: Timeout (20/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html [browser_output.txt]
16:44:46    ERROR - Return code: 2
16:44:46 CRITICAL - # TBPL FAILURE #
16:44:46     INFO - Running pre test command check_screen_resolution with 'bash -c screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'
16:44:46     INFO - Running command: ['bash', '-c', 'screenresolution get && screenresolution list && system_profiler SPDisplaysDataType'] in /builds/slave/talos-slave/test/build
16:44:46     INFO - Copy/paste: bash -c "screenresolution get && screenresolution list && system_profiler SPDisplaysDataType"
16:44:46     INFO -  2014-01-30 16:44:46.430 screenresolution[881:903] starting screenresolution argv=screenresolution get
16:44:46     INFO -  2014-01-30 16:44:46.438 screenresolution[881:903] Display 0: 1600x1200x32
16:44:46     INFO -  2014-01-30 16:44:46.444 screenresolution[883:903] starting screenresolution argv=screenresolution list
16:44:46     INFO -  Available Modes on Display 0
16:44:46     INFO -    1152x870x8 	1152x870x16 	1152x870x32 	1280x1024x8
16:44:46     INFO -    1280x1024x16 	1280x1024x32 	1024x768x8 	1024x768x16
16:44:46     INFO -    1024x768x32 	1024x768x8 	1024x768x16 	1024x768x32
16:44:46     INFO -    1024x768x8 	1024x768x16 	1024x768x32 	800x600x8
16:44:46     INFO -    800x600x16 	800x600x32 	800x600x8 	800x600x16
16:44:46     INFO -    800x600x32 	640x480x8 	640x480x16 	640x480x32
16:44:46     INFO -    640x480x8 	640x480x16 	640x480x32 	1280x1024x8
16:44:46     INFO -    1280x1024x16 	1280x1024x32 	1280x960x8 	1280x960x16
16:44:46     INFO -    1280x960x32 	1280x960x8 	1280x960x16 	1280x960x32
16:44:46     INFO -    1600x1200x8 	1600x1200x16 	1600x1200x32 	1344x1008x8
16:44:46     INFO -    1344x1008x16 	1344x1008x32 Graphics/Displays:
16:44:46     INFO -      NVIDIA GeForce 320M:
16:44:46     INFO -        Chipset Model: NVIDIA GeForce 320M
16:44:46     INFO -        Type: GPU
16:44:46     INFO -        Bus: PCI
16:44:46     INFO -        VRAM (Total): 256 MB
16:44:46     INFO -        Vendor: NVIDIA (0x10de)
16:44:46     INFO -        Device ID: 0x08a4
16:44:46     INFO -        Revision ID: 0x00a2
16:44:46     INFO -        ROM Revision: 3546
16:44:46     INFO -        Displays:
16:44:46     INFO -          Display Connector:
16:44:46     INFO -            Status: No Display Connected
16:44:46     INFO -          Display:
16:44:46     INFO -            Resolution: 1600 x 1200 @ 60 Hz
16:44:46     INFO -            Pixel Depth: 32-Bit Color (ARGB8888)
16:44:46     INFO -            Display Serial Number: 1600x1200 60
16:44:46     INFO -            Main Display: Yes
16:44:46     INFO -            Mirror: Off
16:44:46     INFO -            Online: Yes
16:44:46     INFO -            Rotation: Supported
16:44:46     INFO - Return code: 0
Summary: Intermittent talosError: Timeout (20/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html [browser_output.txt] → Intermittent talosError: Timeout (20/20) exceeded on http://localhost/page_load_test/tp5n/* [browser_output.txt]
That makes it unstarrable, since tbpl does whole-line matching on this error message since there's no "test name" thing in the message that it can detect.
either fix the starring tool, or lets make talos output a better line- how could I modify the subject of this bug to work?  What would I need to put in talos to make this work?
https://wiki.mozilla.org/Sheriffing/Job_Visibility_Policy#6.29_Outputs_failures_in_a_TBPL-starrable_format

If you want to output something variable in the failure line, you'd need more of a "TEST-UNEXPECTED-FAIL | tp5n | Timeout (20/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html [browser_output.txt]" which would then make tbpl search for "tp5n kw:intermittent-failure".

Or, you could output two talosErrors,

talosError: tp5n timeout exceeded
talosError: Timeout (20/20) exceeded on http://localhost/page_load_test/tp5n/alipay.com/www.alipay.com/index.html [browser_output.txt]

which would let tbpl match one bug on the first one, but comment with both, if you want to know what page without opening logs. Or if you don't care what page, drop the page path from the message.
this will make this bug have the ability to be starred properly!
Attachment #8370113 - Flags: review?(dminor)
Attachment #8370113 - Flags: feedback?(philringnalda)
Comment on attachment 8370113 [details] [diff] [review]
output the harness name as an error message (1.0)

Review of attachment 8370113 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good to me.
Attachment #8370113 - Flags: review?(dminor) → review+
Comment on attachment 8370113 [details] [diff] [review]
output the harness name as an error message (1.0)

f+ on the plan, f- on the commit summary ;)
Attachment #8370113 - Flags: feedback?(philringnalda) → feedback+
Depends on: 968095
for future bugs that this shows up, we could see something like this:
TEST-UNEXPECTED-FAIL | Shutdown | application timed out after 330 seconds with no output on toolkit/mozapps/extensions/test/xpinstall

but to keep them all centralized and assuming a low volume, I will enjoy this all being centralized into one bug!
Summary: Intermittent talosError: Timeout (20/20) exceeded on http://localhost/page_load_test/tp5n/* [browser_output.txt] → TEST-UNEXPECTED-FAIL | Shutdown | application timed out after 330 seconds with no output
Um, you surely didn't mean that summary change, did you? Wasn't the change to something like "talosError: timeout in pageloader"?
thanks philor, I was working on browser-chrome yesterday and editing talos bugs.
Summary: TEST-UNEXPECTED-FAIL | Shutdown | application timed out after 330 seconds with no output → talosError: tp5n timeout exceeded
https://tbpl.mozilla.org/php/getParsedLog.php?id=34212758&tree=Fx-Team
Summary: talosError: tp5n timeout exceeded → Intermittent talosError: Timeout in tp5n [browser_output.txt]
Inactive; closing (see bug 1180138).
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: