Closed Bug 1753857 Opened 2 years ago Closed 2 years ago

Intermittent linux ccov /webdriver/tests/bidi/log/entry_added/event_buffer.py | test_console_log_cached_messages[console_api_log] - assert 17 == 2

Categories

(Remote Protocol :: Marionette, defect, P5)

defect

Tracking

(firefox-esr91 unaffected, firefox97 unaffected, firefox98 wontfix, firefox99 fixed)

RESOLVED FIXED
99 Branch
Tracking Status
firefox-esr91 --- unaffected
firefox97 --- unaffected
firefox98 --- wontfix
firefox99 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: jdescottes)

References

Details

(Keywords: intermittent-failure)

Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=366857681&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Qv0sOEMOTpG-t6dOkK9aLA/runs/0/artifacts/public/logs/live_backing.log


[task 2022-02-05T23:12:29.708Z] 23:12:29     INFO - STDOUT: =================================== FAILURES ===================================
[task 2022-02-05T23:12:29.708Z] 23:12:29     INFO - STDOUT: ______________ test_console_log_cached_messages[console_api_log] _______________
[task 2022-02-05T23:12:29.708Z] 23:12:29     INFO - STDOUT: bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f16f87c4320>
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT: current_session = <Session 2dad492c-03a8-4f4e-9488-308a9cdee0e9>
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT: wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f17080c49d8>
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT: inline = <function inline.<locals>.inline at 0x7f17080c4d08>
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT: log_type = 'console_api_log'
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT:     @pytest.mark.asyncio
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT:     @pytest.mark.parametrize("log_type", ["console_api_log", "javascript_error"])
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT:     async def test_console_log_cached_messages(bidi_session,
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT:                                                current_session,
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT:                                                wait_for_event,
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT:                                                inline,
[task 2022-02-05T23:12:29.715Z] 23:12:29     INFO - STDOUT:                                                log_type):
[task 2022-02-05T23:12:29.725Z] 23:12:29     INFO - STDOUT:         # Unsubscribe in case previous tests subscribed to log.entryAdded
[task 2022-02-05T23:12:29.725Z] 23:12:29     INFO - STDOUT:         await bidi_session.session.unsubscribe(events=["log.entryAdded"])
[task 2022-02-05T23:12:29.726Z] 23:12:29     INFO - STDOUT:     
[task 2022-02-05T23:12:29.726Z] 23:12:29     INFO - STDOUT:         # Refresh to make sure no events are cached for the current window global
[task 2022-02-05T23:12:29.726Z] 23:12:29     INFO - STDOUT:         # from previous tests.
[task 2022-02-05T23:12:29.726Z] 23:12:29     INFO - STDOUT:         current_session.refresh()
[task 2022-02-05T23:12:29.733Z] 23:12:29     INFO - 
[task 2022-02-05T23:12:29.733Z] 23:12:29     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/bidi/log/entry_added/event_buffer.py | test_console_log_cached_messages[console_api_log] - assert 17 == 2
[task 2022-02-05T23:12:29.733Z] 23:12:29     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f16f87c4320>
[task 2022-02-05T23:12:29.733Z] 23:12:29     INFO - current_session = <Session 2dad492c-03a8-4f4e-9488-308a9cdee0e9>
[task 2022-02-05T23:12:29.733Z] 23:12:29     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f17080c49d8>
[task 2022-02-05T23:12:29.733Z] 23:12:29     INFO - inline = <function inline.<locals>.inline at 0x7f17080c4d08>
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO - log_type = 'console_api_log'
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO - 
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -     @pytest.mark.asyncio
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -     @pytest.mark.parametrize("log_type", ["console_api_log", "javascript_error"])
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -     async def test_console_log_cached_messages(bidi_session,
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -                                                current_session,
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -                                                wait_for_event,
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -                                                inline,
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -                                                log_type):
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -         # Unsubscribe in case previous tests subscribed to log.entryAdded
[task 2022-02-05T23:12:29.734Z] 23:12:29     INFO -         await bidi_session.session.unsubscribe(events=["log.entryAdded"])
[task 2022-02-05T23:12:29.735Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.735Z] 23:12:29     INFO -         # Refresh to make sure no events are cached for the current window global
[task 2022-02-05T23:12:29.735Z] 23:12:29     INFO -         # from previous tests.
[task 2022-02-05T23:12:29.735Z] 23:12:29     INFO -         current_session.refresh()
[task 2022-02-05T23:12:29.735Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.735Z] 23:12:29     INFO -         # Log a message before subscribing
[task 2022-02-05T23:12:29.735Z] 23:12:29     INFO -         expected_text = create_log(current_session, inline, log_type, "cached_message")
[task 2022-02-05T23:12:29.735Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.736Z] 23:12:29     INFO -         # Track all received log.entryAdded events in the events array
[task 2022-02-05T23:12:29.736Z] 23:12:29     INFO -         events = []
[task 2022-02-05T23:12:29.736Z] 23:12:29     INFO -         async def on_event(method, data):
[task 2022-02-05T23:12:29.736Z] 23:12:29     INFO -             events.append(data)
[task 2022-02-05T23:12:29.736Z] 23:12:29     INFO -         remove_listener = bidi_session.add_event_listener("log.entryAdded", on_event)
[task 2022-02-05T23:12:29.737Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.737Z] 23:12:29     INFO -         # Subscribe
[task 2022-02-05T23:12:29.737Z] 23:12:29     INFO -         on_entry_added = wait_for_event("log.entryAdded")
[task 2022-02-05T23:12:29.738Z] 23:12:29     INFO -         await bidi_session.session.subscribe(events=["log.entryAdded"])
[task 2022-02-05T23:12:29.738Z] 23:12:29     INFO -         await on_entry_added
[task 2022-02-05T23:12:29.738Z] 23:12:29     INFO -         assert len(events) == 1;
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -         # Check the log.entryAdded event received has the expected properties.
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -         assert_base_entry(events[0], text=expected_text)
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -         # Unsubscribe and re-subscribe
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -         await bidi_session.session.unsubscribe(events=["log.entryAdded"])
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -         await bidi_session.session.subscribe(events=["log.entryAdded"])
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.739Z] 23:12:29     INFO -         # Wait for some time to catch all messages.
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -         time.sleep(0.5)
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -         # Check that the cached event was not re-emitted.
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -         assert len(events) == 1;
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -         on_entry_added = wait_for_event("log.entryAdded")
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -         expected_text = create_log(current_session, inline, log_type, "live_message")
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -         await on_entry_added
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -     
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -         # Check that we only received the live message.
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO - >       assert len(events) == 2;
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO - E       assert 17 == 2
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO - E         +17
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO - E         -2
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO - 
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f16f87c4320>
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO - current_session = <Session 2dad492c-03a8-4f4e-9488-308a9cdee0e9>
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO - events     = [{'args': [{'type': 'string', 'value': 'cached_message'}],
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -   'level': 'info',
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -   'method': 'log',
[task 2022-02-05T23:12:29.740Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'text': 'cached_message',
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'timestamp': 1644102744680,
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -  {'args': [{'type': 'string',
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -             'value': 'Registering redirect listener for requestStorageAccess '
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -                      'helper'},
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'text': 'Registering redirect listener for requestStorageAccess helper '
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -           '[object Object]',
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'timestamp': 1644102744971,
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.741Z] 23:12:29     INFO -  {'args': [{'type': 'string', 'value': 'Allowing access to these logos:'},
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'text': 'Allowing access to these logos: '
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -           'https://smartblock.firefox.etp/facebook.svg,https://smartblock.firefox.etp/play.svg',
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'timestamp': 1644102744973,
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -  {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -            {'type': 'string', 'value': 'sub_frame'},
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -            {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.742Z] 23:12:29     INFO -   'text': 'Shimming these sub_frame URLs: *://trends.google.com/trends/embed*',
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -   'timestamp': 1644102744974,
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -  {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -            {'type': 'string', 'value': 'script'},
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -            {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -   'text': 'Shimming these script URLs: '
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -           '*://webcompat-addon-testbed.herokuapp.com/shims_test.js,*://example.com/browser/browser/extensions/webcompat/tests/browser/shims_test.js,*://example.com/browser/browser/extensions/webcompat/tests/browser/shims_test_2.js,*://example.com/browser/browser/extensions/webcompat/tests/browser/shims_test_3.js,*://s7.addthis.com/icons/official-addthis-angularjs/current/dist/official-addthis-angularjs.min.js*,*://track.adform.net/serving/scripts/trackpoint/,*://track.adform.net/serving/scripts/trackpoint/async/,*://acdn.adnxs.com/ast/ast.js,*://*.adnxs.com/*/pb.js,*://*.adnxs.com/*/prebid,*://static.adsafeprotected.com/vans-adapter-google-ima.js,*://pagead2.googlesyndication.com/pagead/js/adsbygoogle.js,*://c.amazon-adsystem.com/aax2/apstag.js,*://auth.9c9media.ca/auth/main.js,*://static.chartbeat.com/js/chartbeat.js,*://static.chartbeat.com/js/chartbeat_video.js,*://static.criteo.net/js/ld/publishertag.js,*://libs.coremetrics.com/eluminate.js,*://connect.facebook.net/*/sdk.js*,*://connect.facebook.net/*/all.js*,*://www.google-analytics.com/analytics.js*,*://www.google-analytics.com/gtm/js*,*://www.googletagmanager.com/gtm.js*,*://www.google-analytics.com/plugins/ua/ec.js,*://ssl.google-analytics.com/ga.js,*://s0.2mdn.net/instream/html5/ima3.js,*://imasdk.googleapis.com/js/sdkloader/ima3.js,*://www.googleadservices.com/pagead/conversion_async.js,*://www.googletagservices.com/tag/js/gpt.js*,*://securepubads.g.doubleclick.net/tag/js/gpt.js*,*://securepubads.g.doubleclick.net/gpt/pubads_impl_*.js*,*://cdn.adsafeprotected.com/iasPET.1.js,*://adservex.media.net/videoAds.js*,*://*.moatads.com/*/moatad.js*,*://*.moatads.com/*/moatapi.js*,*://*.moatads.com/*/moatheader.js*,*://*.moatads.com/*/yi.js*,*://cdn.optimizely.com/js/*.js,*://id.rambler.ru/rambler-id-helper/auth_events.js,*://media.richrelevance.com/rrserver/js/1.2/p13n.js,*://*.vidible.tv/*/vidible-min.js*,*://vdb-cdn-files.s3.amazonaws.com/*/vidible-min.js*',
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -   'timestamp': 1644102744976,
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -  {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:12:29.743Z] 23:12:29     INFO -            {'type': 'string', 'value': 'image'},
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -            {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'text': 'Shimming these image URLs: '
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -           '*://track.adform.net/Serving/TrackPoint/*,*://securepubads.g.doubleclick.net/gampad/*ad-blk*,*://pubads.g.doubleclick.net/gampad/*ad-blk*,*://securepubads.g.doubleclick.net/gampad/*xml_vmap1*,*://pubads.g.doubleclick.net/gampad/*xml_vmap1*,*://securepubads.g.doubleclick.net/gampad/*xml_vmap2*,*://pubads.g.doubleclick.net/gampad/*xml_vmap2*,*://securepubads.g.doubleclick.net/gampad/*ad*,*://pubads.g.doubleclick.net/gampad/*ad*,*://www.facebook.com/platform/impression.php*',
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'timestamp': 1644102744978,
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -  {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -            {'type': 'string', 'value': 'imageset'},
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -            {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.744Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -   'text': 'Shimming these imageset URLs: '
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -           '*://track.adform.net/Serving/TrackPoint/*,*://securepubads.g.doubleclick.net/gampad/*ad-blk*,*://pubads.g.doubleclick.net/gampad/*ad-blk*,*://securepubads.g.doubleclick.net/gampad/*xml_vmap1*,*://pubads.g.doubleclick.net/gampad/*xml_vmap1*,*://securepubads.g.doubleclick.net/gampad/*xml_vmap2*,*://pubads.g.doubleclick.net/gampad/*xml_vmap2*,*://securepubads.g.doubleclick.net/gampad/*ad*,*://pubads.g.doubleclick.net/gampad/*ad*,*://www.facebook.com/platform/impression.php*',
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -   'timestamp': 1644102744979,
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -  {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -            {'type': 'string', 'value': 'xmlhttprequest'},
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -            {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.745Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'text': 'Shimming these xmlhttprequest URLs: '
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -           '*://track.adform.net/Serving/TrackPoint/*,*://securepubads.g.doubleclick.net/gampad/*ad-blk*,*://pubads.g.doubleclick.net/gampad/*ad-blk*,*://securepubads.g.doubleclick.net/gampad/*xml_vmap1*,*://pubads.g.doubleclick.net/gampad/*xml_vmap1*,*://securepubads.g.doubleclick.net/gampad/*xml_vmap2*,*://pubads.g.doubleclick.net/gampad/*xml_vmap2*,*://securepubads.g.doubleclick.net/gampad/*ad*,*://pubads.g.doubleclick.net/gampad/*ad*,*://www.facebook.com/platform/impression.php*',
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'timestamp': 1644102744980,
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -  {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -            {'type': 'string', 'value': 'sub_frame'},
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -            {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'text': 'Shimming these sub_frame URLs: '
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -           '*://tpc.googlesyndication.com/safeframe/*/html/container.html,*://*.safeframe.googlesyndication.com/safeframe/*/html/container.html',
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'timestamp': 1644102744981,
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.746Z] 23:12:29     INFO -  {'args': [{'type': 'string',
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -             'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'text': 'Enabling content scripts for these URLs: '
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -           '*://*.stackblitz.com/*,*://*.stackblitz.io/*',
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'timestamp': 1644102745056,
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -  {'args': [{'type': 'string',
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -             'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.747Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'text': 'Enabling content scripts for these URLs: '
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -           '*://we.hamropatro.com/login*',
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'timestamp': 1644102745057,
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -  {'args': [{'type': 'string',
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -             'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'text': 'Enabling content scripts for these URLs: '
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -           '*://www.avclub.com/*,*://deadspin.com/*,*://gizmodo.com/*,*://jalopnik.com/*,*://jezebel.com/*,*://kotaku.com/*,*://lifehacker.com/*,*://www.theonion.com/*,*://www.theroot.com/*,*://thetakeout.com/*,*://theinventory.com/*',
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'timestamp': 1644102745059,
[task 2022-02-05T23:12:29.748Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -  {'args': [{'type': 'string',
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -             'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -   'text': 'Enabling content scripts for these URLs: '
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -           '*://web.powerva.microsoft.com/*,*://teams.microsoft.com/*',
[task 2022-02-05T23:12:29.749Z] 23:12:29     INFO -   'timestamp': 1644102745061,
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -  {'args': [{'type': 'string',
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -             'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -   'text': 'Enabling content scripts for these URLs: '
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -           '*://www.humblebundle.com/login*,*://www.humblebundle.com/signup*',
[task 2022-02-05T23:12:29.750Z] 23:12:29     INFO -   'timestamp': 1644102745063,
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -  {'args': [{'type': 'string',
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -             'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -   'text': 'Enabling content scripts for these URLs: *://play.history.com/*',
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -   'timestamp': 1644102745064,
[task 2022-02-05T23:12:29.751Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -  {'args': [{'type': 'string',
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -             'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -            None],
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -   'level': 'debug',
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -   'method': 'debug',
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -   'text': 'Enabling content scripts for these URLs: '
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -           '*://account.bellmedia.ca/login*',
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -   'timestamp': 1644102745065,
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -   'type': 'console'},
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -  {'args': [{'type': 'string', 'value': 'live_message'}],
[task 2022-02-05T23:12:29.752Z] 23:12:29     INFO -   'level': 'info',
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO -   'method': 'log',
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO -   'realm': None,
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO -   'text': 'live_message',
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO -   'timestamp': 1644102745239,
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO -   'type': 'console'}]
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - expected_text = 'live_message'
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - inline     = <function inline.<locals>.inline at 0x7f17080c4d08>
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - log_type   = 'console_api_log'
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - on_entry_added = <Future finished result={'args': [{'type': 'string', 'value': 'Registering ...Access helper'}, None], 'level': 'debug', 'method': 'debug', 'realm': None, ...}>
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - on_event   = <function test_console_log_cached_messages.<locals>.on_event at 0x7f17080516a8>
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - remove_listener = <function BidiSession.add_event_listener.<locals>.<lambda> at 0x7f1708051730>
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f17080c49d8>
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - 
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - tests/web-platform/tests/webdriver/tests/bidi/log/entry_added/event_buffer.py:53: AssertionError
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - ...
[task 2022-02-05T23:12:29.753Z] 23:12:29     INFO - TEST-OK | /webdriver/tests/bidi/log/entry_added/event_buffer.py | took 10728ms
Assignee: nobody → jdescottes
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 99 Branch
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.