1573585 - --debugger=rr doesn't seem to work with mochitests any more

Status: RESOLVED FIXED

(Testing :: Mochitest, defect)

Description

[(no longer active)]

Attachment: Example log

Previously I used to be able to invoke a test with the debugger by adding --debugger=rr to the command line. This has stopped working at some point recently, and now the Firefox command that runs when running the test runs without being prefixed with rr.

The only way to run tests under rr now is to prefix the entire mach command with rr which is much slower.

Comment 1

[Geoff Brown [:gbrown]]

I wonder if this is related to the changes for bug 1519369?

Comment 2

[(no longer active)]

Sounds very likely!

Comment 3

[(no longer active)]

Edwin, do you mind having a look please when you are back? Thanks!

Comment 4

[Edwin Takahashi (:egao | infrequent contributor)]

I can take a look, but it's rather odd that this happened given that ./mach test --debugger=rr was one of the conditions I explicitly tested manually prior to landing this.

EDIT: misunderstood the nature of the problem - I tested only that it can properly recognize rr as a debugger.

Comment 5

[Edwin Takahashi (:egao | infrequent contributor)]

I do not have rr installed nor is it available on macOS; is there another way you suggest for testing if the debugger kicks in?

Comment 6

[(no longer active)]

Unfortunately rr is a Linux-only tool. If you have VMWare and are willing to give that a try it should work there. If not, I have a Linux machine which I could give you ssh access to (requires Mozilla VPN), if you'd like, which has it installed. Sorry about the testing pain.

Comment 7

[Edwin Takahashi (:egao | infrequent contributor)]

I will attempt to set up a copy of the current Ubuntu 16.04 image used in CI, clone mozilla-central, install rr and attempt to run the command.

My expectation is that this would provide a close enough approximation of the environment that typical developers would be using. If not I will attempt a virtual machine.

Comment 8

[Edwin Takahashi (:egao | infrequent contributor)]

A local container running the same Ubuntu container in CI was run locally, had necessary dependencies installed and build generated:

worker@099039fb0699:/mozilla-central$ ./mach test toolkit/components/antitracking/test/browser/browser_allowListNotifications.js --debugger=rr
 0:00.28 INFO Checking for ssltunnel processes...
 0:00.28 INFO Checking for xpcshell processes...
 0:00.28 SUITE_START: mochitest-browser - running 1 tests
 0:00.28 INFO Running manifest: toolkit/components/antitracking/test/browser/browser.ini
 0:00.28 INFO The following extra prefs will be set:
  dom.storage_access.prompt.testing=true
  dom.storage_access.prompt.testing.allow=true
  dom.testing.sync-content-blocking-notifications=true
pk12util: PKCS12 IMPORT SUCCESSFUL
 0:00.60 INFO MochitestServer : launching [u'/mozilla-central/objdir-frontend/dist/bin/xpcshell', '-g', u'/mozilla-central/objdir-frontend/dist/bin', '-f', u'/mozilla-central/objdir-frontend/dist/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmp2nZU67.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/mozilla-central/objdir-frontend/_tests/testing/mochitest/server.js']
 0:00.60 INFO runtests.py | Server pid: 21950
 0:00.63 INFO runtests.py | Websocket server pid: 21953
 0:00.65 INFO runtests.py | SSL tunnel pid: 21956
 0:00.75 INFO runtests.py | Running with scheme: http
 0:00.76 INFO runtests.py | Running with e10s: True
 0:00.76 INFO runtests.py | Running with serviceworker_e10s: False
 0:00.76 INFO runtests.py | Running with socketprocess_e10s: False
 0:00.76 INFO runtests.py | Running tests: start.

 0:00.76 INFO Application command: /mozilla-central/objdir-frontend/dist/bin/firefox -marionette -foreground -profile /tmp/tmp2nZU67.mozrunner
 0:00.77 INFO runtests.py | Application pid: 21973
 0:00.77 Started process `GECKO(21973)`
 0:00.80 GECKO(21973) Failed to connect to Mir: Failed to connect to server socket: No such file or directory
 0:00.80 GECKO(21973) Unable to init server: Could not connect: Connection refused
 0:00.80 GECKO(21973) Error: cannot open display: :0
 2:00.83 INFO runtests.py | Waiting for browser...
 2:00.83 Main app process: exit 1
 2:00.83 INFO Buffered messages finished
 2:00.83 ERROR TEST-UNEXPECTED-FAIL | automation.py | application terminated with exit code 1
 2:00.83 INFO runtests.py | Application ran for: 0:02:00.073026
 2:00.83 INFO zombiecheck | Reading PID log: /tmp/tmpSyfxphpidlog
Traceback (most recent call last):
  File "/mozilla-central/objdir-frontend/_tests/testing/mochitest/runtests.py", line 2862, in doTests
    e10s=options.e10s
  File "/mozilla-central/objdir-frontend/_tests/testing/mochitest/runtests.py", line 2371, in runApp
    raise exc(value).with_traceback(tb)
AttributeError: 'timeout' object has no attribute 'with_traceback'
 2:00.84 ERROR Automation Error: Received unexpected exception while running application

 2:00.84 INFO Stopping web server
 2:00.85 INFO Stopping web socket server
 2:00.87 INFO Stopping ssltunnel
 2:00.88 WARNING leakcheck | refcount logging is off, so leaks can't be detected!
 2:00.88 INFO runtests.py | Running tests: end.
 2:00.89 INFO Buffered messages finished
TEST-INFO | checking window state
Browser Chrome Test Summary
	Passed: 0
	Failed: 0
	Todo: 0
	Mode: e10s
*** End BrowserChrome Test Results ***
 2:00.89 INFO Buffered messages finished
 2:00.89 SUITE_END
 2:00.89
Overall Summary
===============

mochitest-browser
~~~~~~~~~~~~~~~~~
Ran 0 checks ()
Expected results: 0
Unexpected results: 0

Unexpected Results
------------------
ERROR TEST-UNEXPECTED-FAIL | automation.py | application terminated with exit code 1
ERROR Automation Error: Received unexpected exception while running application

worker@099039fb0699:/mozilla-central$

I assume this means I would need to have a VM with proper display connected to verify behavior? Since I have not used rr in the past, I am not certain what I should be expecting here.

Comment 9

[Edwin Takahashi (:egao | infrequent contributor)]

I checked out an older mozilla-central push that should not have my changes from bug 1519369, built Firefox then ran the same command:

For more information on what to do now, see https://developer.mozilla.org/docs/Developer_Guide/So_You_Just_Built_Firefox
Test configuration changed. Regenerating backend.
 0:01.09 INFO Checking for ssltunnel processes...
 0:01.09 INFO Checking for xpcshell processes...
 0:01.09 SUITE_START: mochitest-browser - running 1 tests
 0:01.09 INFO Running manifest: toolkit/components/antitracking/test/browser/browser.ini
 0:01.10 INFO The following extra prefs will be set:
  dom.storage_access.prompt.testing=true
  dom.storage_access.prompt.testing.allow=true
  dom.testing.sync-content-blocking-notifications=true
pk12util: PKCS12 IMPORT SUCCESSFUL
 0:01.45 INFO MochitestServer : launching [u'/mozilla-central/objdir-frontend/dist/bin/xpcshell', '-g', u'/mozilla-central/objdir-frontend/dist/bin', '-f', u'/mozilla-central/objdir-frontend/dist/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmphNhgRs.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/mozilla-central/objdir-frontend/_tests/testing/mochitest/server.js']
 0:01.45 INFO runtests.py | Server pid: 23639
 0:01.47 INFO runtests.py | Websocket server pid: 23642
 0:01.50 INFO runtests.py | SSL tunnel pid: 23645
 0:01.80 INFO runtests.py | Running with scheme: http
 0:01.80 INFO runtests.py | Running with e10s: True
 0:01.80 INFO runtests.py | Running with serviceworker_e10s: False
 0:01.81 INFO runtests.py | Running with socketprocess_e10s: False
 0:01.81 INFO runtests.py | Running tests: start.

 0:01.81 INFO Application command: /usr/bin/rr /mozilla-central/objdir-frontend/dist/bin/firefox -marionette -foreground -profile /tmp/tmphNhgRs.mozrunner
 0:01.83 INFO runtests.py | Application pid: 23665
 0:01.83 Started process `GECKO(23665)`
 0:01.86 GECKO(23665) [FATAL /home/roc/rr/rr/src/RecordSession.cc:1796:create()] rr needs /proc/sys/kernel/perf_event_paranoid <= 1, but it is 3.
 0:01.86 GECKO(23665) Change it to 1, or use 'rr record -n' (slow).
 0:01.86 GECKO(23665) Consider putting 'kernel.perf_event_paranoid = 1' in /etc/sysctl.conf
 0:01.86 GECKO(23665) === Start rr backtrace:
 0:01.87 GECKO(23665) /usr/bin/rr(_ZN2rr13dump_rr_stackEv+0x28)[0x55faa8]
 0:01.87 GECKO(23665) /usr/bin/rr(_ZN2rr15notifying_abortEv+0x47)[0x55fb27]
 0:01.87 GECKO(23665) /usr/bin/rr(_ZN2rr13RecordSession6createERKSt6vectorISsSaISsEES5_RKNS_20DisableCPUIDFeaturesENS0_16SyscallBufferingENS_7BindCPUE+0x133)[0x4cb3f3]
 0:01.87 GECKO(23665) /usr/bin/rr(_ZN2rr13RecordCommand3runERSt6vectorISsSaISsEE+0x9e3)[0x4c11a3]
 0:01.87 GECKO(23665) /usr/bin/rr(main+0x244)[0x452504]
 0:01.87 GECKO(23665) /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0)[0x7ffaab190830]
 0:01.87 GECKO(23665) /usr/bin/rr[0x4529ef]
 0:01.87 GECKO(23665) === End rr backtrace
15:01.87 INFO runtests.py | Waiting for browser...
15:01.87 Main app process: killed by SIGIOT
15:01.88 INFO Buffered messages finished
15:01.88 ERROR TEST-UNEXPECTED-FAIL | automation.py | application terminated with exit code -6
15:01.88 INFO runtests.py | Application ran for: 0:15:00.065692
15:01.88 INFO zombiecheck | Reading PID log: /tmp/tmpOzr3Vzpidlog
Traceback (most recent call last):
  File "/mozilla-central/objdir-frontend/_tests/testing/mochitest/runtests.py", line 2848, in doTests
    e10s=options.e10s
  File "/mozilla-central/objdir-frontend/_tests/testing/mochitest/runtests.py", line 2282, in runApp
    self.marionette.start_session()
  File "/mozilla-central/testing/marionette/client/marionette_driver/decorators.py", line 36, in _
    m._handle_socket_failure()
  File "/mozilla-central/testing/marionette/client/marionette_driver/marionette.py", line 650, in _handle_socket_failure
    reraise(exc, val, tb)
  File "/mozilla-central/testing/marionette/client/marionette_driver/decorators.py", line 26, in _
    return func(*args, **kwargs)
  File "/mozilla-central/testing/marionette/client/marionette_driver/marionette.py", line 1108, in start_session
    self.raise_for_port(timeout=timeout)
  File "/mozilla-central/testing/marionette/client/marionette_driver/marionette.py", line 569, in raise_for_port
    self.host, self.port))
timeout: Timed out waiting for connection on 127.0.0.1:2828!
15:01.88 ERROR Automation Error: Received unexpected exception while running application

15:01.89 INFO Stopping web server
15:01.90 INFO Stopping web socket server
15:01.92 INFO Stopping ssltunnel
15:01.95 WARNING leakcheck | refcount logging is off, so leaks can't be detected!
15:01.95 INFO runtests.py | Running tests: end.
15:01.95 INFO Buffered messages finished
TEST-INFO | checking window state
Browser Chrome Test Summary
	Passed: 0
	Failed: 0
	Todo: 0
	Mode: e10s
*** End BrowserChrome Test Results ***
15:01.95 INFO Buffered messages finished
15:01.95 SUITE_END
15:01.95
Overall Summary
===============

mochitest-browser
~~~~~~~~~~~~~~~~~
Ran 0 checks ()
Expected results: 0
Unexpected results: 0
OK

So I now have some baseline to begin from for this bug.

Comment 10

[(no longer active)]

(In reply to Edwin Takahashi (:egao, :etakahashi) from comment #8)

I assume this means I would need to have a VM with proper display connected to verify behavior?

Not necessarily, all that's needed here is paying attention to whether /usr/bin/rr is prepended to the Application command: line in the log output.

Thanks for looking into this!

Comment 11

[Edwin Takahashi (:egao | infrequent contributor)]

Attachment: Bug 1573585 - ensure debugger name is prefixed to the application command when using mach test

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/0b546821bdb2
ensure debugger name is prefixed to the application command when using mach test r=gbrown,Ehsan

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f32912192459
Fix unindented block. a=lint-fix CLOSED TREE

Comment 14

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/0b546821bdb2
https://hg.mozilla.org/mozilla-central/rev/f32912192459