1753855 - Intermittent linux ccov /webdriver/tests/bidi/log/entry_added/console_args.py | test_primitive_types[number] - 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=366863771&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JM7I3sFlTgKG8ljXkrf17w/runs/0/artifacts/public/logs/live_backing.log

---

[task 2022-02-06T00:19:49.164Z] 00:19:49     INFO - TEST-PASS | /webdriver/tests/bidi/log/entry_added/console_args.py | test_primitive_types[null] 
[task 2022-02-06T00:19:49.164Z] 00:19:49     INFO - TEST-PASS | /webdriver/tests/bidi/log/entry_added/console_args.py | test_primitive_types[string] 
[task 2022-02-06T00:19:49.164Z] 00:19:49     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/bidi/log/entry_added/console_args.py | test_primitive_types[number] - AssertionError
[task 2022-02-06T00:19:49.165Z] 00:19:49     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f6050149630>
[task 2022-02-06T00:19:49.165Z] 00:19:49     INFO - current_session = <Session 892aadd0-3b19-4731-9f1e-6a446e7cd61d>
[task 2022-02-06T00:19:49.165Z] 00:19:49     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f6050171f28>
[task 2022-02-06T00:19:49.165Z] 00:19:49     INFO - data = '42', remote_value = {'type': 'number', 'value': 42}
[task 2022-02-06T00:19:49.165Z] 00:19:49     INFO - 
[task 2022-02-06T00:19:49.165Z] 00:19:49     INFO -     @pytest.mark.asyncio
[task 2022-02-06T00:19:49.165Z] 00:19:49     INFO -     @pytest.mark.parametrize("data,remote_value", [
[task 2022-02-06T00:19:49.165Z] 00:19:49     INFO -         ("undefined", {"type": "undefined"}),
[task 2022-02-06T00:19:49.166Z] 00:19:49     INFO -         ("null", {"type": "null"}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         ("bar", {"type": "string", "value": "bar"}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         ("42", {"type": "number", "value": 42}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         ("Number.NaN", {"type": "number", "value": "NaN"}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         ("-0", {"type": "number", "value": "-0"}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         ("Number.POSITIVE_INFINITY", {"type": "number", "value": "+Infinity"}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         ("Number.NEGATIVE_INFINITY", {"type": "number", "value": "-Infinity"}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         ("false", {"type": "boolean", "value": False}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         ("42n", {"type": "bigint", "value": "42"}),
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -     ], ids=[
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "undefined",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "null",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "string",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "number",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "NaN",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "-0",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "+Infinity",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "-Infinity",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "boolean",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -         "bigint",
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -     ])
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -     async def test_primitive_types(bidi_session,
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -                                    current_session,
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -                                    wait_for_event,
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -                                    data,
[task 2022-02-06T00:19:49.167Z] 00:19:49     INFO -                                    remote_value):
[task 2022-02-06T00:19:49.168Z] 00:19:49     INFO -         await bidi_session.session.subscribe(events=["log.entryAdded"])
[task 2022-02-06T00:19:49.168Z] 00:19:49     INFO -     
[task 2022-02-06T00:19:49.168Z] 00:19:49     INFO -         on_entry_added = wait_for_event("log.entryAdded")
[task 2022-02-06T00:19:49.168Z] 00:19:49     INFO -     
[task 2022-02-06T00:19:49.168Z] 00:19:49     INFO -         if remote_value["type"] == "string":
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -             command = "console.log('foo', {!r})"
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -         else:
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -             command = "console.log('foo', {})"
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -     
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -         # TODO: To be replaced with the BiDi implementation of execute_script.
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -         current_session.execute_script(command.format(data))
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -     
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -         event_data = await on_entry_added
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -         args = [
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -             {"type": "string", "value": "foo"},
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -             {"type": remote_value["type"]},
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -         ]
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -         if "value" in remote_value:
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -             args[1].update({"value": remote_value["value"]})
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -     
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -         # First arg is always the first argument as provided to console.log()
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO - >       assert_console_entry(event_data, args=args)
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO - 
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO - args       = [{'type': 'string', 'value': 'foo'}, {'type': 'number', 'value': 42}]
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x7f6050149630>
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO - command    = "console.log('foo', {})"
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO - current_session = <Session 892aadd0-3b19-4731-9f1e-6a446e7cd61d>
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO - data       = '42'
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO - event_data = {'args': [{'type': 'string',
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -            'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -           None],
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -  'level': 'debug',
[task 2022-02-06T00:19:49.170Z] 00:19:49     INFO -  'method': 'debug',
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO -  'realm': None,
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO -  'text': 'Enabling content scripts for these URLs: '
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO -          '*://*.stackblitz.com/*,*://*.stackblitz.io/*',
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO -  'timestamp': 1644106786019,
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO -  'type': 'console'}
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO - on_entry_added = <Future finished result={'args': [{'type': 'string', 'value': 'Enabling con...r these URLs:'}, None], 'level': 'debug', 'method': 'debug', 'realm': None, ...}>
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO - remote_value = {'type': 'number', 'value': 42}
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x7f6050171f28>
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO - 
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO - tests/web-platform/tests/webdriver/tests/bidi/log/entry_added/console_args.py:56: 
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO - 
[task 2022-02-06T00:19:49.171Z] 00:19:49     INFO - entry = {'args': [{'type': 'string', 'value': 'Enabling content scripts for these URLs:'}, None], 'level': 'debug', 'method': 'debug', 'realm': None, ...}
[task 2022-02-06T00:19:49.172Z] 00:19:49     INFO - method = None, level = None, text = None
[task 2022-02-06T00:19:49.172Z] 00:19:49     INFO - args = [{'type': 'string', 'value': 'foo'}, {'type': 'number', 'value': 42}]
[task 2022-02-06T00:19:49.172Z] 00:19:49     INFO - time_start = None, time_end = None, realm = None, stacktrace = None
[task 2022-02-06T00:19:49.172Z] 00:19:49     INFO - 
[task 2022-02-06T00:19:49.172Z] 00:19:49     INFO -     def assert_console_entry(entry,
[task 2022-02-06T00:19:49.172Z] 00:19:49     INFO -                              method=None,
[task 2022-02-06T00:19:49.172Z] 00:19:49     INFO -                              level=None,
[task 2022-02-06T00:19:49.173Z] 00:19:49     INFO -                              text=None,
[task 2022-02-06T00:19:49.173Z] 00:19:49     INFO -                              args=None,
[task 2022-02-06T00:19:49.173Z] 00:19:49     INFO -                              time_start=None,
[task 2022-02-06T00:19:49.174Z] 00:19:49     INFO -                              time_end=None,
[task 2022-02-06T00:19:49.174Z] 00:19:49     INFO -                              realm=None,
[task 2022-02-06T00:19:49.175Z] 00:19:49     INFO -                              stacktrace=None):
[task 2022-02-06T00:19:49.175Z] 00:19:49     INFO -         assert_base_entry(entry, level, text, time_start, time_end, stacktrace)
[task 2022-02-06T00:19:49.175Z] 00:19:49     INFO -     
[task 2022-02-06T00:19:49.175Z] 00:19:49     INFO -         assert "type" in entry
[task 2022-02-06T00:19:49.175Z] 00:19:49     INFO -         assert isinstance(entry["type"], str)
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -         assert entry["type"] == "console"
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -     
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -         assert "method" in entry
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -         assert isinstance(entry["method"], str)
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -         if method is not None:
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -             assert entry["method"] == method
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -     
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -         assert "args" in entry
[task 2022-02-06T00:19:49.176Z] 00:19:49     INFO -         assert isinstance(entry["args"], list)
[task 2022-02-06T00:19:49.177Z] 00:19:49     INFO -         if args is not None:
[task 2022-02-06T00:19:49.177Z] 00:19:49     INFO - >           assert entry["args"] == args
[task 2022-02-06T00:19:49.177Z] 00:19:49     INFO - E           AssertionError
[task 2022-02-06T00:19:49.178Z] 00:19:49     INFO - 
[task 2022-02-06T00:19:49.178Z] 00:19:49     INFO - args       = [{'type': 'string', 'value': 'foo'}, {'type': 'number', 'value': 42}]
[task 2022-02-06T00:19:49.178Z] 00:19:49     INFO - entry      = {'args': [{'type': 'string',
[task 2022-02-06T00:19:49.180Z] 00:19:49     INFO -            'value': 'Enabling content scripts for these URLs:'},
[task 2022-02-06T00:19:49.180Z] 00:19:49     INFO -           None],
[task 2022-02-06T00:19:49.181Z] 00:19:49     INFO -  'level': 'debug',
[task 2022-02-06T00:19:49.181Z] 00:19:49     INFO -  'method': 'debug',
[task 2022-02-06T00:19:49.182Z] 00:19:49     INFO -  'realm': None,
[task 2022-02-06T00:19:49.182Z] 00:19:49     INFO -  'text': 'Enabling content scripts for these URLs: '
[task 2022-02-06T00:19:49.183Z] 00:19:49     INFO -          '*://*.stackblitz.com/*,*://*.stackblitz.io/*',
[task 2022-02-06T00:19:49.183Z] 00:19:49     INFO -  'timestamp': 1644106786019,
[task 2022-02-06T00:19:49.183Z] 00:19:49     INFO -  'type': 'console'}
[task 2022-02-06T00:19:49.183Z] 00:19:49     INFO - level      = None
[task 2022-02-06T00:19:49.184Z] 00:19:49     INFO - method     = None
[task 2022-02-06T00:19:49.184Z] 00:19:49     INFO - realm      = None
[task 2022-02-06T00:19:49.185Z] 00:19:49     INFO - stacktrace = None
[task 2022-02-06T00:19:49.185Z] 00:19:49     INFO - text       = None
[task 2022-02-06T00:19:49.185Z] 00:19:49     INFO - time_end   = None
[task 2022-02-06T00:19:49.186Z] 00:19:49     INFO - time_start = None
[task 2022-02-06T00:19:49.186Z] 00:19:49     INFO - 
[task 2022-02-06T00:19:49.187Z] 00:19:49     INFO - tests/web-platform/tests/webdriver/tests/bidi/log/entry_added/__init__.py:59: AssertionError
[task 2022-02-06T00:19:49.189Z] 00:19:49     INFO - ......
[task 2022-02-06T00:19:49.190Z] 00:19:49     INFO - TEST-OK | /webdriver/tests/bidi/log/entry_added/console_args.py | took 9295ms

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=1753855&startday=2022-01-31&endday=2022-02-06&tree=all

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 2

Platform and build breakdown:

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

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

Comment 3

[BMO Automation]

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