Open Bug 1432176 Opened 6 years ago Updated 15 days ago

Intermittent devtools/client/inspector/rules/test/browser_rules_original-source-link.js | single tracking bug

Categories

(DevTools :: Inspector: Rules, defect, P2)

Product:
DevTools
Component:
Inspector: Rules
Type:
defect

Tracking

(Not tracked)

Status:
REOPENED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, intermittent-testcase, leave-open, Whiteboard: [stockwell disabled])

Attachments

(1 file, 1 obsolete file)

Bug 1432176 - disabled test on win ccov r=jmaher
47 bytes, text/x-phabricator-request
Details | Review 
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
Product: Firefox → DevTools
This has 21 failures in the last 7 days and 68 in the last 30, all on windows10-64-ccov debug : https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2018-11-05&endday=2018-12-05&tree=all&bug=1432176

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=215493375&repo=mozilla-central&lineNumber=17659

Gabriel, could you take a look at what is going here? or should we skip it on coverage? Thank you.
Flags: needinfo?(gl)
Gabriel can you take a look at Cosmin's comment?
Flags: needinfo?(gl)
Flags: needinfo?(gl)

There are 31 failures associated to this bug in the last 7 days. These are occurring on windows10-64-ccov debug builds.

Any updates for this?

There are a total of 32 failures in the last week, all still on windows10-64-ccov debug.

gl: Did you get a chance to take a look at this?

Whiteboard: [stockwell unknown][stockwell needswork]
Priority: P5 → P2

:gl Do you have any updates?
There are 34 failure for the last 7 days.

This bug has failed 34 times in the last 7 days. Occurs on windows10-64-ccov debug build types.

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=228343906&repo=mozilla-central&lineNumber=12993

gl: Any updates on this bug?

In the last 7 days there have been 35 occurrences on Windows 10 64 Ccov debug.

Summary: Intermittent devtools/client/inspector/rules/test/browser_rules_original-source-link.js | Failure: Link text changed to display correct location: doc_sourcemaps.scss:4 - → Perma [tier2] devtools/client/inspector/rules/test/browser_rules_original-source-link.js | Failure: Link text changed to display correct location: doc_sourcemaps.scss:4 -

There have been 35 failures within the last 7 days, all of them on Windows 10x64 ccov debug.
Recent log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=231580293&repo=mozilla-central&lineNumber=14088

This bug has failed 35 times in the last 7 days, all of them on Windows 10x64 ccov debug.

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=233255622&repo=mozilla-central&lineNumber=13727

gl: can you take a look at this bug?

I can consistently reproduce this locally in a debug build with rr record. (No idea about without, not relevant to me.) This failure seems to be blocking the landing of a patch of mine:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=78e88360b414e143b9b508bccdc24099665dd227&group_state=expanded&selectedJob=234029197

so I'm kinda on the hook to figure it out, or see it get figured out. :-) No promises how quickly, tho, as I know none of this code.

The relevant bit of test code that runs here up to the failure is

add_task(async function() {
  info("Setting the " + PREF + " pref to true");
  Services.prefs.setBoolPref(PREF, true);

  await addTab(TESTCASE_URI);
  const {toolbox, inspector, view} = await openRuleView();

  info("Selecting the test node");
  await selectNode("div", inspector);

  await verifyLinkText(SCSS_LOC, view);

and then (dumping mine, obvs)

function verifyLinkText(text, view) {
  info("Verifying that the rule-view stylesheet link is " + text);
  const label = getRuleViewLinkByIndex(view, 1)
    .querySelector(".ruleview-rule-source-label");

  function DUMP() {
    info("Label text is currently " + label.textContent);
    info("Label title is currently " + label.getAttribute("title"));
  }
  Math.sin("first time", label); DUMP();

  return waitForSuccess(function() {
    Math.sin("successive times", label); DUMP();
    return label.textContent == text && label.getAttribute("title") === URL_ROOT + text;
  }, "Link text changed to display correct location: " + text);
}

and what happens is the waitForSuccess never actually happens -- the link text the whole time stays referring to the URL in the HTML source (not the one as given in the corresponding sourcemap), even if I bump up the "loop every 200ms retesting" code in waitForSuccess to loop not 10 times, but 100. The label text visually appears as the CSS_LOC URL, too.

I'll keep investigating tomorrow. I'm not entirely sure where the right place to start is.

Still investigating, mostly by adding the functional equivalent of printf everywhere possible in devtools and other code.

Currently it looks like we have this bit of stack that creates and starts the source-map worker (by which I mean the moral equivalent of new Worker("worker.js") is called, to create a worker, evaluate worker.js's contents, then wait for messages and the like):

 3:13.38 GECKO(9616) 14/exports.startSourceMapWorker@resource://devtools/client/shared/source-map/index.js:185:3
 3:13.38 GECKO(9616) _createSourceMapService@resource://devtools/client/framework/toolbox.js:708:28
 3:13.38 GECKO(9616) get sourceMapURLService@resource://devtools/client/framework/toolbox.js:736:29
 3:13.38 GECKO(9616) get sourceMapURLService@resource://devtools/client/inspector/rules/views/rule-editor.js:108:7
 3:13.38 GECKO(9616) updateSourceLink@resource://devtools/client/inspector/rules/views/rule-editor.js:403:7
 3:13.38 GECKO(9616) _create@resource://devtools/client/inspector/rules/views/rule-editor.js:145:10
 3:13.38 GECKO(9616) RuleEditor@resource://devtools/client/inspector/rules/views/rule-editor.js:79:8

which makes sense. Subsequent to that, SourceMapURLService.prototype.subscribe is called, and that function ends up calling SourceMapURLService.prototype._callOneCallback, which then calls SourceMapURLService.prototype.originalPositionFor, which contains this line:

await this._sourceMapService.getOriginalURLs(urlInfo);

which is expected to send messages to the source map worker.js to fetch the source map, get original URL info, send it back to the devtools UI, which will rewrite the label's text and title. Then the test itself tries to verify the link text is eventually changed. ("Eventually" meaning it tries 10 times every 200ms and fails if it's not there at the end of that -- very dodgy, but in my local debug builds I can bump that to 100 tries and the test still fails, so the error doesn't seem to be just running too slow. Although too-slow could explain some failures in the field, just not the failures I reproduce.)

As far as I can tell, all this logic tracks pretty cleanly and seems right.

At runtime, tho...the worker URL isn't loaded, the worker script isn't evaluated, and so the test just sits there, with the getOriginalURLs serialized message sent to the worker but the worker not responding because it hasn't even evaluated worker.js yet.

So it looks like something is goof about our worker code, such that the new worker for source-map information does nothing and is unresponsive precisely when the test is waiting for it to do things and respond to those previously-sent inputs. Still working out what that might be.

With a little DOM workers assistance from asuth, I've discovered that workerinternals::LoadMainScript(aWorkerPrivate, mScriptURL, WorkerScript, rv); in CompileScriptRunnable::WorkerRun (running on the worker thread) basically hangs between when new Worker('worker.js') happens and when worker.js actually is executed. .

The steps performed by new Worker(url) begin as follows:

  1. [main thread] Create the worker and get/create a thread to run it.
  2. [main thread] Send a CompileScriptRunnable over to the worker's thread to do all the operations of evaluating the worker script.
  3. [worker thread] CSR creates and dispatches a ScriptLoaderRunnable back to the main thread to do everything involved in downloading the script and executing it (note that this means steps happen both on the main thread and on the worker thread). This dispatch ends up reporting back to the worker, by means of CSR using an AutoSyncLoopHolder: a class that creates a nested event loop on the worker thread, to receive the worker-script source text and compile it. Then this syncLoop spins until the event is received.
  4. [main thread] ScriptLoaderRunnable does the AsyncLoad (downloading happens on the network thread) and listens for response data using a LoaderListener.
  5. [main thread] LoaderListener waits til all data is downloaded, then hands it off ScriptLoaderRunnable::OnStreamComplete{,Internal}.
  6. [main thread] SLR::OSCI checks for HTTP errors, gloms up CSP header info to apply to script running and such, does a no-op conversion from UTF-8 to UTF-8 (but that has the effect of copying the data to being JSAPI-allocated), creates a ScriptExecutorRunnable as metaphorical continuation for "execute this script on the worker thread", then calls LoadingFinished.
  7. [main thread] LoadingFinished calls runnable->Dispatch() where runnable is the ScriptExecutorRunnable, dispatching at the event target derived from the AutoSyncLoopHolder's provided target.

All the above steps run sensibly for this code, and worker.js downloads just fine on the main thread, and it all proceeds at an understandable and sensible pace -- no unusual delays here to make a test time out.

(cutting the comment here to get this out of the textbox, at a minimum)

But that last runnable->Dispatch()...it adds the ScriptExecutorRunnable to the syncLoop queue, derived from AutoSyncLoopHolder. And that queue just isn't processed til some distant time, for some reason. Not sure why.

Anyway, that's where I am right now/today. More tomorrow.

...okay, going on further a JS::Evaluate call for the contents of worker.js is encountered at a reasonably sane time -- around event ~514k, from the worker-to-main-thread sync dispatch around event ~500k -- and if I next over that things run a gazillion events well past when the devtools waitForSuccess times out. Bizarro.

On the plus side I seem to be back into mostly understandable JS engine territory again, so I got that going for me, which is nice. Will continue investigating after lunch.

Okay, this is starting to look a little ominous. Turns out the act of parsing/compiling the worker.js script eats up a bunch of time, to start -- and a bunch of the waitForSuccess loop attempts. And notably...obviously lots of time is spent parsing the factory function that contains the guts of worker.js:

(function webpackUniversalModuleDefinition(root, factory) {
        if(typeof exports === 'object' && typeof module === 'object')
                module.exports = factory();
        else if(typeof define === 'function' && define.amd)
                define([], factory);
        else {
                var a = factory();
                for(var i in a) (typeof exports === 'object' ? exports : root)[i] = a[i];
        }
})(typeof self !== 'undefined' ? self : this, function() {
return /******/ (function(modules) { // webpackBootstrap
  // ...generic bootstrapping code...
/******/ })
/************************************************************************/
/******/ ({

/***/ 149:
/***/ (function(module, exports, __webpack_require__) {
// ...particular compiled-together module...
/***/ }),

/***/ 151:
/***/ (function(module, exports, __webpack_require__) {
// ...particular compiled-together module...

// ...and so on

and -- note carefully -- that factory function is syntax-parsed, because it's not preceded by an opening parenthesis or other unary operator that would trigger eager parsing.

So the factory function is going to be syntax-parsed -- and everything inside it that is full/eagerly-parsed (like functions 149 and 151 in the snippet above) is also necessarily syntax-parsed because we can only force an initial full parse, from within full-parsed stuf. Then when it's very shortly called it's going to be re-parsed, and it'll be a full parse.

This is going to be Slow. And given how many waitForSuccess iterations I just watched happen, it is not inconceivable to me (especially since the second full-parse is going to be slower than the initial syntax parse) that all this actually exhausts our waiting-time budget. 😐

Anyway -- for now I will keep examining this trace, but I think there's a good chance we're bumping up against time limits here. 😐 And if that's the case, I'm not sure what the solution is, given this file is auto-generated.

I guess there's always bumping the time to wait in some fashion...which is in general a terrible solution, but may just be inherent to how this test actually does its thing.

Yeah, so -- by the time the waitForSuccess has timed out, the worker thread is still working its way through the DAG module dependency graph being elaborated in worker.js. Looks like this is just a lot of code to run, and a whole bunch of functions' scripts to compile, and if I look at the workers thread when we're back in rule-editor.js, it's still trying to compile scripts to call them and so on.

It looks like all the sub-module functions in worker.js are parenthesized, which means they will be eagerly compiled -- if they are themselves inside functions that are full-parsed/eagerly-parsed. Parenthesizing the factory function passed to webpackUniversalModuleDefinition would help with this, but it's a bit of a hack.

Logan suggests possibly "I bet we can remove that wrapper for this worker, but someone would need to look into it more." and points at https://searchfox.org/mozilla-central/source/devtools/client/debugger/new/webpack.config.js#75 for that. But we're way beyond my ken now for sure. :-) Anyone able to do that/know what to look at to decide on that?

Flags: needinfo?(lsmyth)
Flags: needinfo?(jlaster)

Note to self: to regenerate index.js/worker.js from the source files with changes made to them, cd devtools/client/debugger/new and run yarn && node bin/bundle.js.

Summary: Perma [tier2] devtools/client/inspector/rules/test/browser_rules_original-source-link.js | Failure: Link text changed to display correct location: doc_sourcemaps.scss:4 - → Intermittent devtools/client/inspector/rules/test/browser_rules_original-source-link.js | Failure: Link text changed to display correct location: doc_sourcemaps.scss:4 -

I believe Logan has a patch, which replaces the UMD wrapper.

Flags: needinfo?(jlaster)

I started some Try runs on Friday to see if changing the bundle to remove the UMD wrapper would help, but I'm still seeing failures.

The run is here: https://treeherder.mozilla.org/#/jobs?repo=try&revision=c08680aa1a86b952f4c495fcc91b7d0c569d0691

You can see here that the UMD wrapper was removed: https://hg.mozilla.org/try/rev/fd50451e0bc1#l12.2

Waldo, would you be able to look more into what slowdown is happening now since we shouldn't be doing syntax-parsing on the primary worker content anymore?

Flags: needinfo?(jwalden)

I did a build/rr-run of that, and with bumping the loop count to 1000 and augmenting the printf, the test eventually passes at

6:01.79 INFO Checking (813): Link text changed to display correct location: doc_sourcemaps.scss:4
6:02.00 GECKO(27499) [rr 27513 915559]
6:02.00 INFO Checking (814): Link text changed to display correct location: doc_sourcemaps.scss:4
6:02.21 GECKO(27499) [rr 27513 916102]
6:02.21 INFO Checking (815): Link text changed to display correct location: doc_sourcemaps.scss:4
6:02.23 GECKO(27499) [rr 27513 916144]
6:02.22 PASS Success: Link text changed to display correct location: doc_sourcemaps.scss:4 -

where the waiting started at

2:57.26 INFO Verifying that the rule-view stylesheet link is doc_sourcemaps.scss:4
2:57.27 GECKO(27499) [rr 27513 506608]
2:57.26 INFO Checking (0): Link text changed to display correct location: doc_sourcemaps.scss:4
2:57.83 GECKO(27499) [rr 27513 508146]
2:57.83 INFO Checking (1): Link text changed to display correct location: doc_sourcemaps.scss:4
2:58.07 GECKO(27499) [rr 27513 508843]
2:58.06 INFO Checking (2): Link text changed to display correct location: doc_sourcemaps.scss:4

So, about three minutes' time from first test to first successful test. That does appear to be a win over the previous time -- copying from the #debugger thread, "When I do that, the test does pass; the first print (per --mark-stdio) of waiting is at around 03:20, and the ultimate successful print is at 06:55."

But it isn't enough of a win. Maybe that isn't surprising? I don't know exactly what all the source maps worker has to do, in order to get through having downloaded and dealt with the source map here.

I tested this just the once, under rr. An unfortunate consequence of that is that because of the single-threading of rr, current threads' status is not super-helpful because I think they're just all paused.

(rr) info threads
  Id   Target Id         Frame 
* 1    Thread 27513.27513 (mmap_hardlink_3_firefox) nsGlobalWindowInner::Dump (this=0x7ff137c78800, aStr=...) at /home/jwalden/moz/after/dom/base/nsGlobalWindowInner.cpp:3339
  2    Thread 27513.27517 (gmain) 0x0000000070000002 in ?? ()
  3    Thread 27513.27518 (gdbus) 0x0000000070000002 in ?? ()
  4    Thread 27513.27519 (Gecko_IOThread) 0x0000000070000002 in ?? ()
  5    Thread 27513.27520 (JS Watchdog) 0x0000000070000002 in ?? ()
  6    Thread 27513.27521 (JS Helper) 0x0000000070000002 in ?? ()
  7    Thread 27513.27522 (JS Helper) 0x0000000070000002 in ?? ()
  8    Thread 27513.27523 (Link Monitor) 0x0000000070000002 in ?? ()
  9    Thread 27513.27524 (Socket Thread) 0x0000000070000002 in ?? ()
  10   Thread 27513.27525 (AudioIPC Callba) 0x0000000070000002 in ?? ()
  11   Thread 27513.27526 (AudioIPC Callba) 0x0000000070000002 in ?? ()
  12   Thread 27513.27527 (AudioIPC Server) 0x0000000070000002 in ?? ()
  13   Thread 27513.27528 (AudioIPC Server) 0x0000000070000002 in ?? ()
  14   Thread 27513.27531 (Timer) 0x0000000070000002 in ?? ()
  15   Thread 27513.27533 (Cache2 I/O) 0x0000000070000002 in ?? ()
  16   Thread 27513.27534 (Cookie) 0x0000000070000002 in ?? ()
  17   Thread 27513.27537 (IPDL Background) 0x0000000070000002 in ?? ()
  18   Thread 27513.27568 (GMPThread) 0x0000000070000002 in ?? ()
  19   Thread 27513.27569 (Worker Launcher) 0x0000000070000002 in ?? ()
  20   Thread 27513.27570 (Softwar~cThread) 0x0000000070000002 in ?? ()
  21   Thread 27513.27571 (Compositor) 0x0000000070000002 in ?? ()
  22   Thread 27513.27572 (ImgDecoder #1) 0x0000000070000002 in ?? ()
  23   Thread 27513.27573 (ImageIO) 0x0000000070000002 in ?? ()
  24   Thread 27513.27579 (ImageBr~geChild) 0x0000000070000002 in ?? ()
  25   Thread 27513.27580 (mozStorage #1) 0x0000000070000002 in ?? ()
  26   Thread 27513.27581 (mozStorage #2) 0x0000000070000002 in ?? ()
  27   Thread 27513.27597 (mmap_hardlink_3_firefox) 0x000000007000000e in ?? ()
  28   Thread 27513.27606 (FS Broker 27599) 0x000000007000000e in ?? ()
  29   Thread 27513.27607 (ProcessHangMon) 0x0000000070000002 in ?? ()
  30   Thread 27513.27645 (DataStorage) 0x0000000070000002 in ?? ()
  31   Thread 27513.27647 (Cache I/O) 0x0000000070000002 in ?? ()
  32   Thread 27513.27648 (DOM Worker) 0x0000000070000002 in ?? ()
  33   Thread 27513.27649 (HTML5 Parser) 0x0000000070000002 in ?? ()
  34   Thread 27513.27658 (FS Broker 27651) 0x000000007000000e in ?? ()
  35   Thread 27513.27675 (DOM Worker) 0x0000000070000002 in ?? ()
  36   Thread 27513.27681 (QuotaManager IO) 0x0000000070000002 in ?? ()
  37   Thread 27513.27682 (mozStorage #3) 0x0000000070000002 in ?? ()
  38   Thread 27513.27690 (URL Classifier) 0x0000000070000002 in ?? ()
  39   Thread 27513.27691 (Classif~ Update) 0x0000000070000002 in ?? ()
  40   Thread 27513.27693 (ProxyResolution) 0x0000000070000002 in ?? ()
  41   Thread 27513.27708 (FS Broker 27701) 0x000000007000000e in ?? ()
  42   Thread 27513.27736 (FS Broker 27729) 0x000000007000000e in ?? ()
  43   Thread 27513.27737 (mozStorage #4) 0x0000000070000002 in ?? ()
  44   Thread 27513.27756 (SaveScripts) 0x0000000070000002 in ?? ()
  45   Thread 27513.27777 (FS Broker 27770) 0x000000007000000e in ?? ()
  46   Thread 27513.27815 (FS Broker 27808) 0x000000007000000e in ?? ()
  47   Thread 27513.27848 (ImgDecoder #2) 0x0000000070000002 in ?? ()
  48   Thread 27513.27859 (StreamTrans #36) 0x0000000070000002 in ?? ()
  49   Thread 27513.27860 (StreamTrans #37) 0x0000000070000002 in ?? ()
  50   Thread 27513.27866 (DOM Worker) 0x0000000070000002 in ?? ()

(no idea which thread is the relevant worker, could figure it out if I absolutely had to)

It feels like it might be ideal to have some sort of test harness helper that awaits the source map worker being spun up, and is willing to wait extra-long for that to occur, and will periodically poke the harness saying "I'm still working". Unfortunately that's not quite going to be the same as verifying that the source map worker is spun up on demand as this test happens to exercise. So adding/using such helper would somewhat change the test.

Flags: needinfo?(jwalden)

Okay, I've looked closer, and it looks like it might be the case that the column-computing I do with that patch in place is hitting pathological cases somewhat, that I'd hoped might not matter in practice. Bother. It's probably a function of one super-long line just having a gazillion different small little nodes in it. Filed bug 1542106 to deal with that, then possibly after that I can flip the columns-as-code-points switch.

Unfortunately, with that switch flipped (and with a "print the current iteration every time through, and bump timeout from 10 to 1000" patch applied), the test here still seems to time out locally. But, it times out around iteration 15 or so, not iteration 800+, so that's definite win. However, it does seem to suggest that whatever issues my patch is responsible for, waiting for the source map worker is just longer at least sometimes than our test code is prepared to wait. I don't see any other approach to that particular concern, than bumping the loop-limit up from its current 10. Maybe make it a parameter to the function and have callers provide a timeout in seconds or milliseconds, or something.

The pathological case has now been fixed. I'm inclined to say the only real solution here, given it's just a bunch of code to run, is bumping up the waitForSuccess poll-count a bit. Sadfaces, but I don't see what else to do.

This bug has failed 34 times in the last 7 days. Occurs on windows10-64-ccov, linux64-ccov, windows7-32 on debug build type.

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=242755950&repo=mozilla-central&lineNumber=13974

Bumping the time on this seems fine if someone wants to do that.

Flags: needinfo?(lsmyth)

This bug has failed 33 times in the last 7 days. Occurs on windows10-64-ccov debug build types.

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=245745169&repo=mozilla-central&lineNumber=14947

There are 24 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-05-12&endday=2019-05-19&tree=trunk&bug=1432176

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=247221504&repo=mozilla-central&lineNumber=14867

00:12:09 INFO - TEST-START | devtools/client/inspector/rules/test/browser_rules_original-source-link.js
00:12:18 INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/rules/test/browser_rules_original-source-link.js | Failure: Link text changed to display correct location: doc_sourcemaps.scss:4 -
00:12:18 INFO - Stack trace:
00:12:18 INFO - chrome://mochikit/content/browser-test.js:test_ok:1314
00:12:18 INFO - chrome://mochitests/content/browser/devtools/client/inspector/rules/test/head.js:waitForSuccess:103
00:12:18 INFO - chrome://mochitests/content/browser/devtools/client/inspector/rules/test/browser_rules_original-source-link.js:verifyLinkText:80
00:12:18 INFO - chrome://mochitests/content/browser/devtools/client/inspector/rules/test/browser_rules_original-source-link.js:null:25
00:12:18 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1116
00:12:18 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1144
00:12:18 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1005
00:12:18 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
00:12:18 INFO - Setting the devtools.source-map.client-service.enabled pref to false
00:12:18 INFO - Verifying that the rule-view stylesheet link is doc_sourcemaps.css:1
00:12:18 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.css:1
00:12:18 INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_original-source-link.js | Success: Link text changed to display correct location: doc_sourcemaps.css:1 -
00:12:18 INFO - Setting the devtools.source-map.client-service.enabled pref to true again
00:12:18 INFO - Listening for switch to the style editor
00:12:18 INFO - Finding the stylesheet link and clicking it
00:12:18 INFO - GECKO(5744) | --DOMWINDOW == 3 (00000257C0F8A000) [pid = 1484] [serial = 480] [outer = 0000000000000000] [url = about:blank]
00:12:18 INFO - GECKO(5744) | --DOMWINDOW == 2 (00000257C575E400) [pid = 1484] [serial = 478] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3Cstyle%20type%3D%22text%2Fcss%22%3E%0A%2F*%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92*%2F%23q%7Bcolor%3Aorange%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3C%2Fstyle%3E%3Cdiv%20id%3D%22q%22%3EStyled%20Node%3C%2Fdiv%3E]
00:12:18 INFO - GECKO(5744) | ++DOCSHELL 000001AE6CCA7000 == 11 [pid = 10244] [id = {893a97aa-9f9a-4f7b-bd32-2eebf42a14d3}]
00:12:18 INFO - GECKO(5744) | ++DOMWINDOW == 41 (000001AE657DB7A0) [pid = 10244] [serial = 2080] [outer = 0000000000000000]
00:12:18 INFO - GECKO(5744) | ++DOMWINDOW == 42 (000001AE75E6FC00) [pid = 10244] [serial = 2081] [outer = 000001AE657DB7A0]
00:12:18 INFO - GECKO(5744) | [Parent 10244, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x805D0021: file z:/build/build/src/modules/libjar/nsJARChannel.cpp, line 994
00:12:18 INFO - GECKO(5744) | [Parent 10244, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 134
00:12:18 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 245}]
00:12:19 INFO - GECKO(5744) | ++DOCSHELL 000001AE741E5800 == 12 [pid = 10244] [id = {302053cc-1da1-4d1d-ac24-6a06ea111f64}]
00:12:19 INFO - GECKO(5744) | ++DOMWINDOW == 43 (000001AE6FF3D100) [pid = 10244] [serial = 2082] [outer = 0000000000000000]
00:12:19 INFO - Console message: [JavaScript Warning: "XUL box for h3 element contained an inline #text child, forcing all its children to be wrapped in a block." {file: "chrome://devtools/content/styleeditor/index.xul" line: 0}]
00:12:19 INFO - GECKO(5744) | ++DOMWINDOW == 44 (000001AE764EF000) [pid = 10244] [serial = 2083] [outer = 000001AE6FF3D100]
00:12:20 INFO - Console message: [JavaScript Warning: "XUL box for h3 element contained an inline #text child, forcing all its children to be wrapped in a block." {file: "chrome://devtools/content/styleeditor/index.xul" line: 0}]
00:12:20 INFO - GECKO(5744) | [Parent 10244, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 134
00:12:20 INFO - GECKO(5744) | ++DOCSHELL 000001AE661E0000 == 13 [pid = 10244] [id = {459f0729-408e-4c94-941f-236741099aa4}]
00:12:20 INFO - GECKO(5744) | ++DOMWINDOW == 45 (000001AE71AEB5C0) [pid = 10244] [serial = 2084] [outer = 0000000000000000]
00:12:20 INFO - Console message: [JavaScript Warning: "XUL box for h3 element contained an inline #text child, forcing all its children to be wrapped in a block." {file: "chrome://devtools/content/styleeditor/index.xul" line: 0}]
00:12:20 INFO - GECKO(5744) | ++DOMWINDOW == 46 (000001AE76495400) [pid = 10244] [serial = 2085] [outer = 000001AE71AEB5C0]
00:12:21 INFO - GECKO(5744) | [Parent 10244, Main Thread] WARNING: NS_ENSURE_TRUE(frame) failed: file z:/build/build/src/dom/events/ContentEventHandler.cpp, line 1305
00:12:21 INFO - Original source editor selected
00:12:21 INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_original-source-link.js | selected stylesheet is correct one -
00:12:21 INFO - TEST-PASS | devtools/client/inspector/rules/test/browser_rules_original-source-link.js | cursor is at correct line number in original source -
00:12:21 INFO - Clearing the devtools.source-map.client-service.enabled pref
00:12:21 INFO - Leaving test bound
00:12:22 INFO - GECKO(5744) | ++DOMWINDOW == 47 (000001AE6E10A000) [pid = 10244] [serial = 2086] [outer = 000001AE657212E0]
00:12:22 INFO - GECKO(5744) | --DOMWINDOW == 1 (0000015608A197A0) [pid = 5508] [serial = 192] [outer = 0000000000000000] [url = about:blank]
00:12:22 INFO - GECKO(5744) | console.warn: "Error while detaching the thread front: 'detach' request packet to 'server1.conn165.child1/context18' can't be sent as the connection is closed."
00:12:26 INFO - GECKO(5744) | --DOMWINDOW == 0 (00000156037D3000) [pid = 5508] [serial = 193] [outer = 0000000000000000] [url = about:blank]
00:12:27 INFO - GECKO(5744) | --DOMWINDOW == 46 (000001AE70833000) [pid = 10244] [serial = 2065] [outer = 0000000000000000] [url = about:blank]
00:12:27 INFO - GECKO(5744) | --DOMWINDOW == 45 (000001AE71867000) [pid = 10244] [serial = 2063] [outer = 0000000000000000] [url = about:blank]
00:12:27 INFO - GECKO(5744) | --DOMWINDOW == 44 (000001AE6B4EC400) [pid = 10244] [serial = 2055] [outer = 0000000000000000] [url = chrome://devtools/content/inspector/markup/markup.xhtml]
00:12:27 INFO - GECKO(5744) | --DOMWINDOW == 43 (000001AE6B410800) [pid = 10244] [serial = 2049] [outer = 0000000000000000] [url = about:blank]
00:12:27 INFO - GECKO(5744) | --DOMWINDOW == 42 (000001AE6B408400) [pid = 10244] [serial = 2047] [outer = 0000000000000000] [url = about:devtools-toolbox]
00:12:27 INFO - GECKO(5744) | --DOMWINDOW == 41 (000001AE66806000) [pid = 10244] [serial = 2058] [outer = 0000000000000000] [url = about:blank]
00:12:27 INFO - GECKO(5744) | --DOMWINDOW == 40 (000001AE6C7CFC00) [pid = 10244] [serial = 2056] [outer = 0000000000000000] [url = about:blank]
00:12:27 INFO - GECKO(5744) | --DOCSHELL 000001AE5BD6A800 == 12 [pid = 10244] [id = {b8a532fb-5af2-434f-aa54-68d4c83cf5dc}] [url = chrome://devtools/content/inspector/index.xhtml]
00:12:27 INFO - GECKO(5744) | --DOCSHELL 000001AE673FA800 == 11 [pid = 10244] [id = {a611e442-90c9-411f-9927-95698cace9e1}] [url = about:blank]
00:12:27 INFO - GECKO(5744) | --DOCSHELL 000001AE6CCA9800 == 10 [pid = 10244] [id = {9ec3723e-2e3c-42be-84e7-226cf54136e2}] [url = chrome://devtools/content/inspector/markup/markup.xhtml]
00:12:27 INFO - GECKO(5744) | --DOCSHELL 000001AE6CCA7000 == 9 [pid = 10244] [id = {893a97aa-9f9a-4f7b-bd32-2eebf42a14d3}] [url = chrome://devtools/content/styleeditor/index.xul]
00:12:27 INFO - GECKO(5744) | --DOCSHELL 000001AE741E5800 == 8 [pid = 10244] [id = {302053cc-1da1-4d1d-ac24-6a06ea111f64}] [url = chrome://devtools/content/shared/sourceeditor/codemirror/cmiframe.html]
00:12:27 INFO - GECKO(5744) | --DOCSHELL 000001AE673AB800 == 7 [pid = 10244] [id = {db9353f6-f4c6-4100-afc0-f90cead5b8a1}] [url = about:blank]
00:12:27 INFO - GECKO(5744) | --DOCSHELL 000001AE661E0000 == 6 [pid = 10244] [id = {459f0729-408e-4c94-941f-236741099aa4}] [url = chrome://devtools/content/shared/sourceeditor/codemirror/cmiframe.html]
00:12:28 INFO - Removing tab.
00:12:28 INFO - Waiting for event: 'TabClose' on [object XULElement].
00:12:28 INFO - Got event: 'TabClose' on [object XULElement].
00:12:28 INFO - GECKO(5744) | [Child 3784, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
00:12:28 INFO - Tab removed and finished closing
00:12:28 INFO - GECKO(5744) | MEMORY STAT | vsize 2104676MB | vsizeMaxContiguous 66971414MB | residentFast 553MB | heapAllocated 165MB
00:12:28 INFO - TEST-OK | devtools/client/inspector/rules/test/browser_rules_original-source-link.js | took 19059ms
00:12:28 INFO - GECKO(5744) | ++DOCSHELL 0000015608102800 == 1 [pid = 5508] [id = {2ae659c4-9d53-43b4-8e97-d3ea074fc0da}]
00:12:28 INFO - GECKO(5744) | ++DOMWINDOW == 1 (0000015608A19020) [pid = 5508] [serial = 194] [outer = 0000000000000000]
00:12:28 INFO - GECKO(5744) | [Child 5508, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
00:12:28 INFO - GECKO(5744) | [Child 5508, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
00:12:28 INFO - GECKO(5744) | ++DOMWINDOW == 2 (00000156037CE800) [pid = 5508] [serial = 195] [outer = 0000015608A19020]
00:12:28 INFO - checking window state

Would the current fix be to increase the setTimeout time in https://searchfox.org/mozilla-central/source/devtools/client/inspector/rules/test/head.js#93? What would be an appropriate time based on our current testing?

Flags: needinfo?(gl) → needinfo?(jwalden)

I haven't the foggiest idea what an "appropriate" time increase would be. You could either deal by increasing the 200 there, or by increasing the 10 looping attempts. Increasing the 200 delays finishing for cases where the success condition happens very fast, so I'd probably increase the 10. But whether to increase literally here, or make it a user-provided value (probably in ms, converted to an iteration multiple), could be debated. (The debatability of what to do is why I never circled back to this to do a patch -- too much digression from why I actually had to look at this initially. :-( )

Flags: needinfo?(jwalden)

There are 32 failures in the last 7 days on linux64-ccov & windows10-64-ccov debug: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-05-27&endday=2019-06-03&tree=trunk&bug=1432176

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=249638669&repo=mozilla-central&lineNumber=16474

Jeff could take another look at it or redirect to someone else?

Flags: needinfo?(jwalden)

I was mostly doing driveby looking here in pursuit of unrelated work, so I probably should fob this off on the actual component people. Redirecting to triage owner...

Flags: needinfo?(jwalden) → needinfo?(gl)

Sorry to circle back, I don't want to take any guesses from my side since I haven't investigated this to the level you have, and I would assume no one else would necessarily know better. What would be a good looping attempt number for this intermittent?

Flags: needinfo?(gl) → needinfo?(jwalden)

There are 30 total failures in the last 7 days on windows10-64-ccov platform, debug build type.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=255087953&repo=mozilla-central&lineNumber=17164

11:44:35 INFO - TEST-START | devtools/client/inspector/rules/test/browser_rules_original-source-link.js
11:44:35 INFO - GECKO(3540) | ++DOCSHELL 0000025A42E19000 == 2 [pid = 4268] [id = {cb6c27e4-5bed-4ba9-a1e0-3db56c3e0415}]
11:44:35 INFO - GECKO(3540) | ++DOMWINDOW == 3 (0000025A436435C0) [pid = 4268] [serial = 397] [outer = 0000000000000000]
11:44:35 INFO - GECKO(3540) | [Child 4268, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
11:44:35 INFO - GECKO(3540) | [Parent 3036, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file z:/build/build/src/obj-firefox/dist/include\mozilla/RangeBoundary.h, line 79
11:44:35 INFO - GECKO(3540) | [Parent 3036, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file z:/build/build/src/obj-firefox/dist/include\mozilla/RangeBoundary.h, line 79
11:44:35 INFO - GECKO(3540) | [Child 4268, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
11:44:35 INFO - GECKO(3540) | ++DOMWINDOW == 4 (0000025A42E4F800) [pid = 4268] [serial = 398] [outer = 0000025A436435C0]
11:44:35 INFO - GECKO(3540) | --DOMWINDOW == 31 (000001C89F19E980) [pid = 3036] [serial = 1915] [outer = 0000000000000000] [url = chrome://devtools/content/inspector/index.xhtml]
11:44:35 INFO - GECKO(3540) | --DOMWINDOW == 30 (000001C897FE2200) [pid = 3036] [serial = 1912] [outer = 0000000000000000] [url = about:devtools-toolbox]
11:44:35 INFO - GECKO(3540) | --DOMWINDOW == 29 (000001C89F19F100) [pid = 3036] [serial = 1917] [outer = 0000000000000000] [url = about:blank]
11:44:35 INFO - GECKO(3540) | --DOMWINDOW == 28 (000001C8A56F53E0) [pid = 3036] [serial = 1921] [outer = 0000000000000000] [url = chrome://devtools/content/inspector/markup/markup.xhtml]
11:44:35 INFO - GECKO(3540) | ++DOMWINDOW == 5 (0000025A42ED6400) [pid = 4268] [serial = 399] [outer = 0000025A436435C0]
11:44:36 INFO - GECKO(3540) | ++DOCSHELL 000001C898504000 == 11 [pid = 3036] [id = {982fe225-4975-484e-88e5-fb44f9550995}]
11:44:36 INFO - GECKO(3540) | ++DOMWINDOW == 29 (000001C897FE2200) [pid = 3036] [serial = 1934] [outer = 0000000000000000]
11:44:36 INFO - GECKO(3540) | ++DOMWINDOW == 30 (000001C89BC88400) [pid = 3036] [serial = 1935] [outer = 000001C897FE2200]
11:44:36 INFO - GECKO(3540) | ++DOMWINDOW == 31 (000001C89C482800) [pid = 3036] [serial = 1936] [outer = 000001C897FE2200]
11:44:37 INFO - GECKO(3540) | ++DOCSHELL 000001C89851A000 == 12 [pid = 3036] [id = {4ed11852-61ba-451e-87f2-e8333da46e25}]
11:44:37 INFO - GECKO(3540) | ++DOMWINDOW == 32 (000001C89F19E980) [pid = 3036] [serial = 1937] [outer = 0000000000000000]
11:44:37 INFO - GECKO(3540) | ++DOMWINDOW == 33 (000001C89D9C5800) [pid = 3036] [serial = 1938] [outer = 000001C89F19E980]
11:44:37 INFO - GECKO(3540) | [Parent 3036, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x805D0021: file z:/build/build/src/modules/libjar/nsJARChannel.cpp, line 994
11:44:37 INFO - GECKO(3540) | ++DOCSHELL 000001C89DAE5800 == 13 [pid = 3036] [id = {5c747490-37be-4be6-ab1f-aa00723d4de6}]
11:44:37 INFO - GECKO(3540) | ++DOMWINDOW == 34 (000001C89F19F100) [pid = 3036] [serial = 1939] [outer = 0000000000000000]
11:44:38 INFO - GECKO(3540) | --DOMWINDOW == 3 (0000021FBD6385C0) [pid = 1756] [serial = 276] [outer = 0000000000000000] [url = about:blank]
11:44:38 INFO - GECKO(3540) | ++DOMWINDOW == 35 (000001C8A27DA400) [pid = 3036] [serial = 1940] [outer = 000001C89F19F100]
11:44:38 INFO - GECKO(3540) | --DOCSHELL 000001C88E07C000 == 12 [pid = 3036] [id = {98907e25-e379-4973-9dfa-d7a162050204}] [url = chrome://devtools/content/inspector/index.xhtml]
11:44:38 INFO - GECKO(3540) | --DOCSHELL 000001C898509000 == 11 [pid = 3036] [id = {556d4ee4-9fbc-4b5e-acbb-e9b835fb2a44}] [url = about:devtools-toolbox]
11:44:38 INFO - GECKO(3540) | --DOCSHELL 000001C8998D1000 == 10 [pid = 3036] [id = {a1431eff-0b06-4942-a67c-7144004400b0}] [url = about:blank]
11:44:38 INFO - GECKO(3540) | --DOCSHELL 000001C8A324E800 == 9 [pid = 3036] [id = {da639a3a-b58e-4399-b63b-c34fa6ce1b31}] [url = chrome://devtools/content/inspector/markup/markup.xhtml]
11:44:38 INFO - GECKO(3540) | ++DOCSHELL 000001C8A10B6800 == 10 [pid = 3036] [id = {543b5f15-6ce0-4564-9aa0-e54727ed3f10}]
11:44:38 INFO - GECKO(3540) | ++DOMWINDOW == 36 (000001C8A56F5200) [pid = 3036] [serial = 1941] [outer = 0000000000000000]
11:44:38 INFO - GECKO(3540) | ++DOMWINDOW == 37 (000001C8A2B6F800) [pid = 3036] [serial = 1942] [outer = 000001C8A56F5200]
11:44:38 INFO - GECKO(3540) | ++DOCSHELL 000001C8A12DF000 == 11 [pid = 3036] [id = {6f245e24-f61d-43ce-a2f2-cd733390ba21}]
11:44:38 INFO - GECKO(3540) | ++DOMWINDOW == 38 (000001C8A56F53E0) [pid = 3036] [serial = 1943] [outer = 0000000000000000]
11:44:39 INFO - GECKO(3540) | --DOCSHELL 0000025A42E1A000 == 1 [pid = 4268] [id = {c7b6672d-2148-48da-94dd-fe8347b8ea4f}] [url = data:text/html;charset=utf-8,%3Cstyle%20type%3D%22text%2Fcss%22%3E%0A%2F*%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92*%2F%23q%7Bcolor%3Aorange%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3C%2Fstyle%3E%3Cdiv%20id%3D%22q%22%3EStyled%20Node%3C%2Fdiv%3E]
11:44:39 INFO - GECKO(3540) | ++DOMWINDOW == 39 (000001C89DB8E000) [pid = 3036] [serial = 1944] [outer = 000001C8A56F53E0]
11:44:39 INFO - GECKO(3540) | [Parent 3036, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x805D0021: file z:/build/build/src/modules/libjar/nsJARChannel.cpp, line 994
11:44:39 INFO - GECKO(3540) | --DOMWINDOW == 4 (0000025A43643020) [pid = 4268] [serial = 394] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3Cstyle%20type%3D%22text%2Fcss%22%3E%0A%2F*%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92*%2F%23q%7Bcolor%3Aorange%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3C%2Fstyle%3E%3Cdiv%20id%3D%22q%22%3EStyled%20Node%3C%2Fdiv%3E]
11:44:40 INFO - GECKO(3540) | --DOCSHELL 000001C8A10B6800 == 10 [pid = 3036] [id = {543b5f15-6ce0-4564-9aa0-e54727ed3f10}] [url = about:blank]
11:44:40 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
11:44:40 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
11:44:40 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
11:44:40 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
11:44:40 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
11:44:41 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
11:44:41 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
11:44:41 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
11:44:41 INFO - GECKO(3540) | [Parent 3036, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 42
11:44:41 INFO - GECKO(3540) | [Parent 3036, Main Thread] WARNING: '!principal', file z:/build/build/src/netwerk/cookie/CookieSettings.cpp, line 131
11:44:41 INFO - GECKO(3540) | [Parent 3036, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/toolkit/components/antitracking/StorageAccess.cpp, line 30
11:44:42 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
11:44:42 INFO - GECKO(3540) | --DOMWINDOW == 2 (0000021FB85D6800) [pid = 1756] [serial = 277] [outer = 0000000000000000] [url = about:blank]
11:44:42 INFO - GECKO(3540) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
11:44:43 INFO - GECKO(3540) | --DOCSHELL 000001EF01930800 == 0 [pid = 6712] [id = {5f22cc89-6001-4641-ac93-668f281938c9}] [url = about:blank]
11:44:43 INFO - GECKO(3540) | --DOMWINDOW == 3 (0000025A42EDC000) [pid = 4268] [serial = 396] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3Cstyle%20type%3D%22text%2Fcss%22%3E%0A%2F*%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92%F0%9F%86%92*%2F%23q%7Bcolor%3Aorange%7D%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%3C%2Fstyle%3E%3Cdiv%20id%3D%22q%22%3EStyled%20Node%3C%2Fdiv%3E]
11:44:43 INFO - GECKO(3540) | --DOMWINDOW == 2 (0000025A42E4F800) [pid = 4268] [serial = 398] [outer = 0000000000000000] [url = about:blank]
11:44:44 INFO - TEST-INFO | started process screenshot
11:44:44 INFO - TEST-INFO | screenshot: exit 0
11:44:44 INFO - Buffered messages logged at 11:44:35
11:44:44 INFO - Entering test bound
11:44:44 INFO - Setting the devtools.source-map.client-service.enabled pref to true
11:44:44 INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/inspector/rules/test/doc_sourcemaps.html
11:44:44 INFO - Console message: [JavaScript Error: "uncaught exception: Object" {file: "resource://testing-common/PromiseTestUtils.jsm" line: 112}]
11:44:44 INFO - Buffered messages logged at 11:44:36
11:44:44 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/devtools/client/inspector/rules/test/doc_sourcemaps.html" line: 0}]
11:44:44 INFO - Tab added and finished loading
11:44:44 INFO - Loading the helper frame script chrome://mochitests/content/browser/devtools/client/inspector/rules/test/doc_frame_script.js
11:44:44 INFO - Opening the inspector
11:44:44 INFO - Opening the toolbox
11:44:44 INFO - Buffered messages logged at 11:44:40
11:44:44 INFO - Toolbox opened and focused
11:44:44 INFO - Buffered messages logged at 11:44:41
11:44:44 INFO - Selecting the test node
11:44:44 INFO - Selecting the node for 'div'
11:44:44 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
11:44:44 INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
11:44:44 INFO - Verifying that the rule-view stylesheet link is doc_sourcemaps.scss:4
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Buffered messages logged at 11:44:42
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Buffered messages logged at 11:44:43
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Buffered messages logged at 11:44:44
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.scss:4
11:44:44 INFO - Buffered messages finished
11:44:44 INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/rules/test/browser_rules_original-source-link.js | Failure: Link text changed to display correct location: doc_sourcemaps.scss:4 -
11:44:44 INFO - Stack trace:
11:44:44 INFO - chrome://mochikit/content/browser-test.js:test_ok:1576
11:44:44 INFO - chrome://mochitests/content/browser/devtools/client/inspector/rules/test/head.js:waitForSuccess:106
11:44:44 INFO - chrome://mochitests/content/browser/devtools/client/inspector/rules/test/browser_rules_original-source-link.js:verifyLinkText:85
11:44:44 INFO - chrome://mochitests/content/browser/devtools/client/inspector/rules/test/browser_rules_original-source-link.js:null:25
11:44:44 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1346
11:44:44 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1381
11:44:44 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1209
11:44:44 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
11:44:44 INFO - Setting the devtools.source-map.client-service.enabled pref to false
11:44:44 INFO - Verifying that the rule-view stylesheet link is doc_sourcemaps.css:1
11:44:44 INFO - Checking: Link text changed to display correct location: doc_sourcemaps.css:1

Gabriel, this is failing only on mozilla-central, can you please take a look?

Flags: needinfo?(gl)

Would you be able to disable the test for the appropriate platforms?

Flags: needinfo?(gl) → needinfo?(ccoroiu)

Gabriel the disabling patch is now reviewed, should we land it?

Flags: needinfo?(ccoroiu) → needinfo?(gl)

(In reply to Andreea Pavel [:apavel] from comment #82)

Gabriel the disabling patch is now reviewed, should we land it?

Yes, let's go ahead with it.

Flags: needinfo?(gl)

https://hg.mozilla.org/mozilla-central/rev/31fbfa7fbb91

Status: REOPENED → RESOLVED
Closed: 6 years ago → 5 years ago
status-firefox70: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 70
Assignee: nobody → apavel
Pushed by csabou@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/a2fb26817b52
Disable tests on ccov for frequent failures. a=testonly

Disabled also browser_rules_original-source-link2.js (cause that was failing too) and also on linux: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-06-13&endday=2019-07-13&tree=trunk&bug=1432176
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=256337367&repo=mozilla-central&lineNumber=17328

Status: RESOLVED → REOPENED
status-firefox70: fixed → ---
Resolution: FIXED → ---
Whiteboard: [stockwell unknown][stockwell needswork] → [stockwell disabled]
Target Milestone: Firefox 70 → ---

https://hg.mozilla.org/mozilla-central/rev/a2fb26817b52

Status: REOPENED → RESOLVED
Closed: 5 years ago → 5 years ago
status-firefox70: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 70
Status: RESOLVED → REOPENED
status-firefox70: fixed → ---
Keywords: leave-open
Resolution: FIXED → ---
Target Milestone: Firefox 70 → ---
Assignee: apavel → nobody

Only skipped on ccov, no frequent failures, clearing the ni

Flags: needinfo?(jwalden)
Severity: normal → S3
Keywords: intermittent-testcase
Summary: Intermittent devtools/client/inspector/rules/test/browser_rules_original-source-link.js | Failure: Link text changed to display correct location: doc_sourcemaps.scss:4 - → Intermittent devtools/client/inspector/rules/test/browser_rules_original-source-link.js | single trackingbug
Summary: Intermittent devtools/client/inspector/rules/test/browser_rules_original-source-link.js | single trackingbug → Intermittent devtools/client/inspector/rules/test/browser_rules_original-source-link.js | single tracking bug
Attachment #9386285 - Attachment is obsolete: true
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: