Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=151906738&repo=mozilla-central https://queue.taskcluster.net/v1/task/T8DfLUVjTc6df15i-BbJ3w/runs/0/artifacts/public/logs/live_backing.log 23:53:44 INFO - 323 INFO TEST-START | devtools/client/netmonitor/test/browser_net_filter-flags.js 23:53:44 INFO - GECKO(8692) | ++DOCSHELL 000002A874D9D000 == 2 [pid = 888] [id = {eaca31c1-147a-43bc-99b5-2f5d7b31d9fa}] 23:53:44 INFO - GECKO(8692) | ++DOMWINDOW == 3 (000002A8728B7470) [pid = 888] [serial = 137] [outer = 0000000000000000] 23:53:45 INFO - GECKO(8692) | ++DOMWINDOW == 4 (000002A875869C00) [pid = 888] [serial = 138] [outer = 000002A8728B7470] 23:53:49 INFO - GECKO(8692) | --DOMWINDOW == 22 (000001D745DCC800) [pid = 8692] [serial = 180] [outer = 0000000000000000] [url = about:blank] 23:53:49 INFO - GECKO(8692) | --DOMWINDOW == 21 (000001D745DC8000) [pid = 8692] [serial = 178] [outer = 0000000000000000] [url = about:devtools-toolbox] 23:53:49 INFO - GECKO(8692) | --DOMWINDOW == 20 (000001D7450C7C00) [pid = 8692] [serial = 177] [outer = 0000000000000000] [url = about:blank] 23:53:49 INFO - GECKO(8692) | --DOCSHELL 000001D739F3F000 == 5 [pid = 8692] [id = {b85abb5c-f55a-4604-bb9f-4678688c88bf}] 23:53:49 INFO - GECKO(8692) | --DOCSHELL 000001D7465B0000 == 4 [pid = 8692] [id = {aab171fc-7cdc-416e-9958-9c7c1314f56f}] 23:53:50 INFO - GECKO(8692) | --DOMWINDOW == 19 (000001D744AE6850) [pid = 8692] [serial = 181] [outer = 0000000000000000] [url = about:devtools-toolbox] 23:53:50 INFO - GECKO(8692) | --DOMWINDOW == 18 (000001D744AE6A40) [pid = 8692] [serial = 184] [outer = 0000000000000000] [url = chrome://devtools/content/netmonitor/index.html] 23:53:50 INFO - GECKO(8692) | [Parent 8692, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/netwerk/base/nsChannelClassifier.cpp, line 344 23:53:50 INFO - GECKO(8692) | ++DOMWINDOW == 5 (000002A875870400) [pid = 888] [serial = 139] [outer = 000002A8728B7470] 23:53:51 INFO - GECKO(8692) | ++DOCSHELL 000001D739F50800 == 5 [pid = 8692] [id = {321f4875-48d2-4c41-ae87-7956a3a1d80d}] 23:53:51 INFO - GECKO(8692) | ++DOMWINDOW == 19 (000001D744AE6850) [pid = 8692] [serial = 191] [outer = 0000000000000000] 23:53:51 INFO - GECKO(8692) | ++DOMWINDOW == 20 (000001D74529C400) [pid = 8692] [serial = 192] [outer = 000001D744AE6850] 23:53:51 INFO - GECKO(8692) | ++DOMWINDOW == 21 (000001D745559800) [pid = 8692] [serial = 193] [outer = 000001D744AE6850] 23:53:51 INFO - GECKO(8692) | [Parent 8692, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004001: file z:/build/build/src/dom/xul/nsXULPrototypeCache.cpp, line 352 23:53:52 INFO - GECKO(8692) | ++DOCSHELL 000001D748DE6000 == 6 [pid = 8692] [id = {9aa9987b-fc94-437a-9341-287205b44ef6}] 23:53:52 INFO - GECKO(8692) | ++DOMWINDOW == 22 (000001D744AE6A40) [pid = 8692] [serial = 194] [outer = 0000000000000000] 23:53:52 INFO - GECKO(8692) | ++DOMWINDOW == 23 (000001D7460BE000) [pid = 8692] [serial = 195] [outer = 000001D744AE6A40] 23:53:52 INFO - GECKO(8692) | --DOCSHELL 000002A874DA3800 == 1 [pid = 888] [id = {6dd97cea-ec4b-480e-983a-a569023ffc8c}] 23:53:53 INFO - GECKO(8692) | --DOCSHELL 0000020DD5C31000 == 0 [pid = 6136] [id = {48350afe-904f-4be8-9c52-80ce6d73b120}] 23:53:53 INFO - GECKO(8692) | --DOMWINDOW == 4 (000002A8728B7A40) [pid = 888] [serial = 133] [outer = 0000000000000000] [url = http://example.com/browser/devtools/client/netmonitor/test/html_filter-test-page.html] 23:53:53 INFO - GECKO(8692) | --DOMWINDOW == 1 (0000020DDB2BA470) [pid = 6136] [serial = 48] [outer = 0000000000000000] [url = about:blank] 23:53:57 INFO - GECKO(8692) | ++DOMWINDOW == 5 (000002A87561B800) [pid = 888] [serial = 140] [outer = 000002A8728B7470] 23:53:57 INFO - GECKO(8692) | --DOMWINDOW == 0 (0000020DDDC2EC00) [pid = 6136] [serial = 49] [outer = 0000000000000000] [url = about:blank] 23:53:59 INFO - GECKO(8692) | --DOMWINDOW == 4 (000002A875869C00) [pid = 888] [serial = 138] [outer = 0000000000000000] [url = about:blank] 23:53:59 INFO - GECKO(8692) | --DOMWINDOW == 3 (000002A875624000) [pid = 888] [serial = 136] [outer = 0000000000000000] [url = http://example.com/browser/devtools/client/netmonitor/test/html_filter-test-page.html] 23:54:31 INFO - GECKO(8692) | --DOMWINDOW == 22 (000001D745556800) [pid = 8692] [serial = 182] [outer = 0000000000000000] [url = about:blank] 23:54:31 INFO - GECKO(8692) | --DOMWINDOW == 21 (000001D745DCC000) [pid = 8692] [serial = 185] [outer = 0000000000000000] [url = about:blank] 23:54:31 INFO - GECKO(8692) | --DOMWINDOW == 20 (000001D745DCF000) [pid = 8692] [serial = 183] [outer = 0000000000000000] [url = about:devtools-toolbox] 23:54:39 INFO - GECKO(8692) | --DOMWINDOW == 19 (000001D744AE6660) [pid = 8692] [serial = 189] [outer = 0000000000000000] [url = chrome://devtools/content/netmonitor/index.html] 23:54:39 INFO - GECKO(8692) | --DOMWINDOW == 18 (000001D744AE6470) [pid = 8692] [serial = 186] [outer = 0000000000000000] [url = about:devtools-toolbox] 23:55:01 INFO - GECKO(8692) | --DOMWINDOW == 2 (000002A875870400) [pid = 888] [serial = 139] [outer = 0000000000000000] [url = http://example.com/browser/devtools/client/netmonitor/test/html_filter-test-page.html] 23:55:14 INFO - GECKO(8692) | --DOMWINDOW == 17 (000001D7460B5C00) [pid = 8692] [serial = 190] [outer = 0000000000000000] [url = about:blank] 23:55:14 INFO - GECKO(8692) | --DOMWINDOW == 16 (000001D745DD0800) [pid = 8692] [serial = 188] [outer = 0000000000000000] [url = about:devtools-toolbox] 23:55:14 INFO - GECKO(8692) | --DOMWINDOW == 15 (000001D745DC6400) [pid = 8692] [serial = 187] [outer = 0000000000000000] [url = about:blank] 23:55:42 INFO - GECKO(8692) | [Parent 8692, Main Thread] WARNING: NS_ENSURE_SUCCESS(EnsureScriptEnvironment(), nullptr) failed with result 0x80040111: file z:/build/build/src/docshell/base/nsDocShell.cpp, line 4751 23:55:42 INFO - GECKO(8692) | [Parent 8692, Main Thread] WARNING: NS_ENSURE_TRUE(doc) failed: file z:/build/build/src/dom/base/Location.cpp, line 959 23:55:42 INFO - GECKO(8692) | [Parent 8692, Main Thread] WARNING: NS_ENSURE_TRUE(!mIsBeingDestroyed) failed: file z:/build/build/src/docshell/base/nsDocShell.cpp, line 10025 23:55:43 INFO - TEST-INFO | started process screenshot 23:55:43 INFO - TEST-INFO | screenshot: exit 0 23:55:43 INFO - <snipped 575 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test> 23:55:43 INFO - Buffered messages logged at 23:55:28 23:55:43 INFO - 324 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 3 has visibility=false - 23:55:43 INFO - 325 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 4 has visibility=false - 23:55:43 INFO - 326 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 5 has visibility=false - 23:55:43 INFO - 327 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 6 has visibility=false - 23:55:43 INFO - 328 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 7 has visibility=false - 23:55:43 INFO - 329 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 8 has visibility=false - 23:55:43 INFO - 330 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 9 has visibility=false - 23:55:43 INFO - Buffered messages logged at 23:55:31 23:55:43 INFO - 331 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of items in the requests menu. - 23:55:43 INFO - 332 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of visible items in the requests menu. - 23:55:43 INFO - 333 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 0 has visibility=true - 23:55:43 INFO - 334 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 1 has visibility=true - 23:55:43 INFO - 335 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 2 has visibility=true - 23:55:43 INFO - 336 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 3 has visibility=true - 23:55:43 INFO - 337 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 4 has visibility=true - 23:55:43 INFO - 338 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 5 has visibility=true - 23:55:43 INFO - 339 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 6 has visibility=true - 23:55:43 INFO - 340 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 7 has visibility=true - 23:55:43 INFO - 341 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 8 has visibility=true - 23:55:43 INFO - 342 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 9 has visibility=true - 23:55:43 INFO - Buffered messages logged at 23:55:32 23:55:43 INFO - 343 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of items in the requests menu. - 23:55:43 INFO - 344 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of visible items in the requests menu. - 23:55:43 INFO - 345 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 0 has visibility=false - 23:55:43 INFO - 346 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 1 has visibility=false - 23:55:43 INFO - 347 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 2 has visibility=false - 23:55:43 INFO - 348 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 3 has visibility=false - 23:55:43 INFO - 349 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 4 has visibility=false - 23:55:43 INFO - 350 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 5 has visibility=false - 23:55:43 INFO - 351 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 6 has visibility=false - 23:55:43 INFO - 352 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 7 has visibility=false - 23:55:43 INFO - 353 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 8 has visibility=false - 23:55:43 INFO - 354 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 9 has visibility=false - 23:55:43 INFO - Buffered messages logged at 23:55:35 23:55:43 INFO - 355 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of items in the requests menu. - 23:55:43 INFO - 356 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of visible items in the requests menu. - 23:55:43 INFO - 357 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 0 has visibility=true - 23:55:43 INFO - 358 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 1 has visibility=true - 23:55:43 INFO - 359 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 2 has visibility=true - 23:55:43 INFO - 360 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 3 has visibility=true - 23:55:43 INFO - 361 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 4 has visibility=true - 23:55:43 INFO - 362 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 5 has visibility=true - 23:55:43 INFO - 363 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 6 has visibility=true - 23:55:43 INFO - 364 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 7 has visibility=true - 23:55:43 INFO - 365 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 8 has visibility=true - 23:55:43 INFO - 366 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 9 has visibility=true - 23:55:43 INFO - Buffered messages logged at 23:55:36 23:55:43 INFO - 367 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of items in the requests menu. - 23:55:43 INFO - 368 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of visible items in the requests menu. - 23:55:43 INFO - 369 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 0 has visibility=false - 23:55:43 INFO - 370 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 1 has visibility=false - 23:55:43 INFO - 371 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 2 has visibility=false - 23:55:43 INFO - 372 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 3 has visibility=false - 23:55:43 INFO - 373 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 4 has visibility=false - 23:55:43 INFO - 374 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 5 has visibility=false - 23:55:43 INFO - 375 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 6 has visibility=false - 23:55:43 INFO - 376 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 7 has visibility=false - 23:55:43 INFO - 377 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 8 has visibility=false - 23:55:43 INFO - 378 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 9 has visibility=false - 23:55:43 INFO - Buffered messages logged at 23:55:38 23:55:43 INFO - 379 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of items in the requests menu. - 23:55:43 INFO - 380 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of visible items in the requests menu. - 23:55:43 INFO - 381 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 0 has visibility=true - 23:55:43 INFO - 382 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 1 has visibility=true - 23:55:43 INFO - 383 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 2 has visibility=true - 23:55:43 INFO - 384 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 3 has visibility=true - 23:55:43 INFO - 385 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 4 has visibility=true - 23:55:43 INFO - 386 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 5 has visibility=true - 23:55:43 INFO - 387 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 6 has visibility=true - 23:55:43 INFO - 388 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 7 has visibility=true - 23:55:43 INFO - 389 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 8 has visibility=true - 23:55:43 INFO - 390 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 9 has visibility=true - 23:55:43 INFO - Buffered messages logged at 23:55:39 23:55:43 INFO - 391 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of items in the requests menu. - 23:55:43 INFO - 392 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of visible items in the requests menu. - 23:55:43 INFO - 393 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 0 has visibility=false - 23:55:43 INFO - 394 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 1 has visibility=false - 23:55:43 INFO - 395 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 2 has visibility=false - 23:55:43 INFO - 396 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 3 has visibility=false - 23:55:43 INFO - 397 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 4 has visibility=false - 23:55:43 INFO - 398 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 5 has visibility=false - 23:55:43 INFO - 399 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 6 has visibility=false - 23:55:43 INFO - 400 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 7 has visibility=false - 23:55:43 INFO - 401 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 8 has visibility=false - 23:55:43 INFO - 402 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 9 has visibility=false - 23:55:43 INFO - Buffered messages logged at 23:55:42 23:55:43 INFO - 403 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of items in the requests menu. - 23:55:43 INFO - 404 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | There should be a specific amount of visible items in the requests menu. - 23:55:43 INFO - 405 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 0 has visibility=false - 23:55:43 INFO - 406 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 1 has visibility=false - 23:55:43 INFO - 407 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 2 has visibility=true - 23:55:43 INFO - 408 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 3 has visibility=true - 23:55:43 INFO - 409 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 4 has visibility=true - 23:55:43 INFO - 410 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 5 has visibility=true - 23:55:43 INFO - 411 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 6 has visibility=true - 23:55:43 INFO - 412 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 7 has visibility=true - 23:55:43 INFO - 413 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 8 has visibility=true - 23:55:43 INFO - 414 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-flags.js | The item at index 9 has visibility=false - 23:55:43 INFO - 415 INFO Destroying the specified network monitor. 23:55:43 INFO - 416 INFO Wait for completion of all NetworkUpdateEvents packets... 23:55:43 INFO - 417 INFO All pending requests finished. 23:55:43 INFO - 418 INFO Removing tab. 23:55:43 INFO - 419 INFO Waiting for event: 'TabClose' on [object XULElement]. 23:55:43 INFO - 420 INFO Got event: 'TabClose' on [object XULElement]. 23:55:43 INFO - 421 INFO Tab removed and finished closing 23:55:43 INFO - 422 INFO Leaving test bound 23:55:43 INFO - Buffered messages logged at 23:55:43 23:55:43 INFO - 423 INFO finish() was called, cleaning up... 23:55:43 INFO - Buffered messages finished 23:55:43 ERROR - 424 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_filter-flags.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 23:55:43 INFO - GECKO(8692) | MEMORY STAT | vsize 2500MB | vsizeMaxContiguous 132032482MB | residentFast 621MB | heapAllocated 216MB 23:55:43 INFO - 425 INFO TEST-OK | devtools/client/netmonitor/test/browser_net_filter-flags.js | took 118235ms 23:55:43 INFO - GECKO(8692) | ++DOCSHELL 0000020DD5C31000 == 1 [pid = 6136] [id = {3c5ff97a-1a5c-4e39-82eb-c1738fbf9e82}] 23:55:43 INFO - GECKO(8692) | ++DOMWINDOW == 1 (0000020DDB2BA470) [pid = 6136] [serial = 50] [outer = 0000000000000000] 23:55:43 INFO - GECKO(8692) | ++DOMWINDOW == 2 (0000020DDDC2EC00) [pid = 6136] [serial = 51] [outer = 0000020DDB2BA470]

This bug has failed 39 times in the last week, most fails happen on Windows10-64 and a few of them on Linux, Build types are debug and a few opt. Here is a recent log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=153046367&lineNumber=8438 And here is a part of the log: 00:32:41 INFO - 415 INFO Destroying the specified network monitor. 00:32:41 INFO - 416 INFO Wait for completion of all NetworkUpdateEvents packets... 00:32:41 INFO - 417 INFO All pending requests finished. 00:32:41 INFO - 418 INFO Removing tab. 00:32:41 INFO - 419 INFO Waiting for event: 'TabClose' on [object XULElement]. 00:32:41 INFO - Buffered messages logged at 00:32:41 00:32:41 INFO - 420 INFO Got event: 'TabClose' on [object XULElement]. 00:32:41 INFO - 421 INFO Tab removed and finished closing 00:32:41 INFO - 422 INFO Leaving test bound 00:32:41 INFO - 423 INFO finish() was called, cleaning up... 00:32:41 INFO - Buffered messages finished 00:32:41 ERROR - 424 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_filter-flags.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 00:32:41 INFO - GECKO(3816) | MEMORY STAT | vsize 2482MB | vsizeMaxContiguous 132143966MB | residentFast 591MB | heapAllocated 192MB 00:32:41 INFO - 425 INFO TEST-OK | devtools/client/netmonitor/test/browser_net_filter-flags.js | took 112484ms 00:32:41 INFO - GECKO(3816) | ++DOCSHELL 000001ADDD35D000 == 1 [pid = 1336] [id = {ffb1d838-b043-4348-ba6a-d64b4f174abe}] 00:32:41 INFO - GECKO(3816) | ++DOMWINDOW == 1 (000001ADE29B5470) [pid = 1336] [serial = 50] [outer = 0000000000000000] 00:32:41 INFO - GECKO(3816) | ++DOMWINDOW == 2 (000001ADE5706400) [pid = 1336] [serial = 51] [outer = 000001ADE29B5470] 00:32:41 INFO - 426 INFO checking window state 00:32:41 INFO - 427 INFO TEST-START | devtools/client/netmonitor/test/browser_net_footer-summary.js 00:32:41 INFO - GECKO(3816) | ++DOCSHELL 000002819BCA3000 == 2 [pid = 2456] [id = {68532770-639d-461e-be7a-2895b305c2da}] 00:32:41 INFO - GECKO(3816) | ++DOMWINDOW == 3 (00000281997BEA40) [pid = 2456] [serial = 141] [outer = 0000000000000000] 00:32:42 INFO - GECKO(3816) | ++DOMWINDOW == 4 (000002819C41CC00) [pid = 2456] [serial = 142] [outer = 00000281997BEA40] 00:32:45 INFO - GECKO(3816) | --DOCSHELL 000001F154E18000 == 5 [pid = 3816] [id = {fb3d0d50-a8d1-460b-a7fc-fc1599c5e54b}] 00:32:45 INFO - GECKO(3816) | --DOCSHELL 000001F14624A000 == 4 [pid = 3816] [id = {afcedb70-0082-4b7a-a6e1-a90a6960d8e9}] 00:32:45 INFO - GECKO(3816) | [Parent 3816, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file z:/build/build/src/netwerk/base/nsChannelClassifier.cpp, line 344 Hi Honza: Can you please take a look at this bug?

Hello, This bug has failed 35 times in the last 7 days, almost all fails happen on windows10-64-ccov but some are also happening on linux64-ccov. Here is a recent log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=153586159&lineNumber=8445+ And here is a part of a log: 01:47:21 INFO - 415 INFO Destroying the specified network monitor. 01:47:21 INFO - 416 INFO Wait for completion of all NetworkUpdateEvents packets... 01:47:21 INFO - 417 INFO All pending requests finished. 01:47:21 INFO - 418 INFO Removing tab. 01:47:21 INFO - 419 INFO Waiting for event: 'TabClose' on [object XULElement]. 01:47:21 INFO - 420 INFO Got event: 'TabClose' on [object XULElement]. 01:47:21 INFO - 421 INFO Tab removed and finished closing 01:47:21 INFO - 422 INFO Leaving test bound 01:47:21 INFO - 423 INFO finish() was called, cleaning up... 01:47:21 INFO - Buffered messages finished 01:47:21 ERROR - 424 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_filter-flags.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 01:47:21 INFO - GECKO(1508) | MEMORY STAT | vsize 2477MB | vsizeMaxContiguous 131503225MB | residentFast 619MB | heapAllocated 219MB 01:47:21 INFO - 425 INFO TEST-OK | devtools/client/netmonitor/test/browser_net_filter-flags.js | took 111654ms 01:47:21 INFO - GECKO(1508) | ++DOCSHELL 000002AD4A65D000 == 1 [pid = 5136] [id = {959eced6-b1b3-4a58-aad2-1619d3277b8e}] 01:47:21 INFO - GECKO(1508) | ++DOMWINDOW == 1 (000002AD4FBC1470) [pid = 5136] [serial = 50] [outer = 0000000000000000] 01:47:21 INFO - GECKO(1508) | ++DOMWINDOW == 2 (000002AD52530C00) [pid = 5136] [serial = 51] [outer = 000002AD4FBC1470] 01:47:21 INFO - 426 INFO checking window state 01:47:22 INFO - 427 INFO TEST-START | devtools/client/netmonitor/test/browser_net_footer-summary.js 01:47:22 INFO - GECKO(1508) | ++DOCSHELL 000001BDD6AA2000 == 2 [pid = 668] [id = {f601e2ec-c0c7-4604-ac77-ae86a129e082}] 01:47:22 INFO - GECKO(1508) | ++DOMWINDOW == 3 (000001BDD44BAA40) [pid = 668] [serial = 141] [outer = 0000000000000000] 01:47:22 INFO - GECKO(1508) | ++DOMWINDOW == 4 (000001BDD7225C00) [pid = 668] [serial = 142] [outer = 000001BDD44BAA40] Hi :Honza, can you please take a look?

This test was updated by bug 1418927 just before it started failing. It needs to be optimized, split up, or it can requestLongerTimeout(), or perhaps it should just be skipped on coverage builds.

According to the error log from comment 4, the test finished normally without errors but it exceeded timeout threshold. So adding requestLongerTimeout() is supposed to fix this issue. Honza, could you take a quick look? thanks.

Comment on attachment 8939446 [details] Bug 1425733 - Add requestLongerTimeout() in browser_net_filter-flags.js https://reviewboard.mozilla.org/r/209766/#review215368 Looks reasonable, let's see if it helps. Thanks Ricky! Honza

Pushed by rchien@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/c827e3de4db7 Add requestLongerTimeout() in browser_net_filter-flags.js r=Honza

According to latest https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1425733&startday=2018-01-01&endday=2018-01-07&tree=all, the failure rate has gone since patch landed.

Fail reappeared on https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&revision=415e9b18ca2a1532086d5e2d5d21343cd004b5fd Log: https://treeherder.mozilla.org/logviewer.html#?job_id=167073574&repo=mozilla-central&lineNumber=7292