1753854 - Intermittent linux ccov /webdriver/tests/bidi/log/entry_added/console.py | test_text_with_argument_variation[array of strings] - AssertionError

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO - TEST-PASS | /webdriver/tests/bidi/log/entry_added/console.py | test_text_with_argument_variation[empty object] 
[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/bidi/log/entry_added/console.py | test_text_with_argument_variation[array of strings] - AssertionError
[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7fb74c192438>
[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO - current_session = <Session 67452bb0-a0f1-4c15-8f44-c1cffba1413c>
[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7fb74c126730>
[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO - log_argument = "['1', '2', '3']", expected_text = '1,2,3'
[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO - 
[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO -     @pytest.mark.asyncio
[task 2022-02-05T23:11:52.704Z] 23:11:52     INFO -     @pytest.mark.parametrize("log_argument, expected_text", [
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         ("'TEST'", "TEST"),
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         ("'TWO', 'PARAMETERS'", "TWO PARAMETERS"),
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         ("{}", "[object Object]"),
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         ("['1', '2', '3']", "1,2,3"),
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         ("null, undefined", "null undefined"),
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -     ], ids=[
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         'single string',
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         'two strings',
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         'empty object',
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         'array of strings',
[task 2022-02-05T23:11:52.705Z] 23:11:52     INFO -         'null and undefined',
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -     ])
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -     async def test_text_with_argument_variation(bidi_session,
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -                                                 current_session,
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -                                                 wait_for_event,
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -                                                 log_argument,
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -                                                 expected_text):
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -         await bidi_session.session.subscribe(events=["log.entryAdded"])
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -     
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -         on_entry_added = wait_for_event("log.entryAdded")
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -     
[task 2022-02-05T23:11:52.706Z] 23:11:52     INFO -         # TODO: To be replaced with the BiDi implementation of execute_script.
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO -         current_session.execute_script(f"console.log({log_argument})")
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO -     
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO -         event_data = await on_entry_added
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO -     
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO - >       assert_console_entry(event_data, text=expected_text)
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO - 
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7fb74c192438>
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO - current_session = <Session 67452bb0-a0f1-4c15-8f44-c1cffba1413c>
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO - event_data = {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:11:52.707Z] 23:11:52     INFO -           {'type': 'string', 'value': 'imageset'},
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO -           {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO -           None],
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO -  'level': 'debug',
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO -  'method': 'debug',
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO -  'realm': None,
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO -  'text': 'Shimming these imageset URLs: '
[task 2022-02-05T23:11:52.708Z] 23:11:52     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:11:52.708Z] 23:11:52     INFO -  'timestamp': 1644102708809,
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO -  'type': 'console'}
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO - expected_text = '1,2,3'
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO - log_argument = "['1', '2', '3']"
[task 2022-02-05T23:11:52.708Z] 23:11:52     INFO - on_entry_added = <Future finished result={'args': [{'type': 'string', 'value': 'Shimming these'}, {'type': 'string', 'value': 'imageset'}, {'type': 'string', 'value': 'URLs:'}, None], 'level': 'debug', 'method': 'debug', 'realm': None, ...}>
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7fb74c126730>
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO - 
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO - tests/web-platform/tests/webdriver/tests/bidi/log/entry_added/console.py:37: 
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO - tests/web-platform/tests/webdriver/tests/bidi/log/entry_added/__init__.py:45: in assert_console_entry
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO -     assert_base_entry(entry, level, text, time_start, time_end, stacktrace)
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO -         args       = None
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO -         entry      = {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO -           {'type': 'string', 'value': 'imageset'},
[task 2022-02-05T23:11:52.709Z] 23:11:52     INFO -           {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -           None],
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -  'level': 'debug',
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -  'method': 'debug',
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -  'realm': None,
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -  'text': 'Shimming these imageset URLs: '
[task 2022-02-05T23:11:52.710Z] 23:11:52     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:11:52.710Z] 23:11:52     INFO -  'timestamp': 1644102708809,
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -  'type': 'console'}
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -         level      = None
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -         method     = None
[task 2022-02-05T23:11:52.710Z] 23:11:52     INFO -         realm      = None
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO -         stacktrace = None
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO -         text       = '1,2,3'
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO -         time_end   = None
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO -         time_start = None
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO - 
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO - entry = {'args': [{'type': 'string', 'value': 'Shimming these'}, {'type': 'string', 'value': 'imageset'}, {'type': 'string', 'value': 'URLs:'}, None], 'level': 'debug', 'method': 'debug', 'realm': None, ...}
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO - level = None, text = '1,2,3', time_start = None, time_end = None
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO - stacktrace = None
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO - 
[task 2022-02-05T23:11:52.711Z] 23:11:52     INFO -     def assert_base_entry(entry,
[task 2022-02-05T23:11:52.712Z] 23:11:52     INFO -                           level=None,
[task 2022-02-05T23:11:52.712Z] 23:11:52     INFO -                           text=None,
[task 2022-02-05T23:11:52.713Z] 23:11:52     INFO -                           time_start=None,
[task 2022-02-05T23:11:52.713Z] 23:11:52     INFO -                           time_end=None,
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -                           stacktrace=None):
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -         assert "level" in entry
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -         assert isinstance(entry["level"], str)
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -         if level is not None:
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -             assert entry["level"] == level
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -     
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -         assert "text" in entry
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -         assert isinstance(entry["text"], str)
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -         if text is not None:
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO - >           assert entry["text"] == text
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO - E           AssertionError
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO - 
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO - entry      = {'args': [{'type': 'string', 'value': 'Shimming these'},
[task 2022-02-05T23:11:52.717Z] 23:11:52     INFO -           {'type': 'string', 'value': 'imageset'},
[task 2022-02-05T23:11:52.718Z] 23:11:52     INFO -           {'type': 'string', 'value': 'URLs:'},
[task 2022-02-05T23:11:52.718Z] 23:11:52     INFO -           None],
[task 2022-02-05T23:11:52.718Z] 23:11:52     INFO -  'level': 'debug',
[task 2022-02-05T23:11:52.718Z] 23:11:52     INFO -  'method': 'debug',
[task 2022-02-05T23:11:52.718Z] 23:11:52     INFO -  'realm': None,
[task 2022-02-05T23:11:52.718Z] 23:11:52     INFO -  'text': 'Shimming these imageset URLs: '
[task 2022-02-05T23:11:52.718Z] 23:11:52     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:11:52.718Z] 23:11:52     INFO -  'timestamp': 1644102708809,
[task 2022-02-05T23:11:52.719Z] 23:11:52     INFO -  'type': 'console'}
[task 2022-02-05T23:11:52.719Z] 23:11:52     INFO - level      = None
[task 2022-02-05T23:11:52.719Z] 23:11:52     INFO - stacktrace = None
[task 2022-02-05T23:11:52.719Z] 23:11:52     INFO - text       = '1,2,3'
[task 2022-02-05T23:11:52.719Z] 23:11:52     INFO - time_end   = None
[task 2022-02-05T23:11:52.719Z] 23:11:52     INFO - time_start = None
[task 2022-02-05T23:11:52.720Z] 23:11:52     INFO - 
[task 2022-02-05T23:11:52.720Z] 23:11:52     INFO - tests/web-platform/tests/webdriver/tests/bidi/log/entry_added/__init__.py:15: AssertionError
[task 2022-02-05T23:11:52.720Z] 23:11:52     INFO - ............
[task 2022-02-05T23:11:52.720Z] 23:11:52     INFO - TEST-OK | /webdriver/tests/bidi/log/entry_added/console.py | took 9597ms

Comment 1

[Intermittent Failures Robot]

1 failures in 3165 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1753854&startday=2022-01-31&endday=2022-02-06&tree=all

Comment 2

[Intermittent Failures Robot]

1 failures in 3711 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1753854&startday=2022-02-07&endday=2022-02-13&tree=all

Comment 3

[Intermittent Failures Robot]

1 failures in 3281 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1753854&startday=2022-02-14&endday=2022-02-20&tree=all

Comment 4

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.