1048547 - [mozlog] Passing kwarg without using argument name is broken

Status: RESOLVED FIXED

(Testing :: Mozbase, defect)

Description

[James Graham [:jgraham]]

See the bottom of https://s3.amazonaws.com/archive.travis-ci.org/jobs/31608098/log.txt for example. This breaks servo. It turns out the the code to emulate python's handling of arguments doesn't. Attaching a simpler version that seems to work better.

Comment 1

[James Graham [:jgraham]]

Attachment: Improve mozlog.structured argument handling

Comment 2

[James Graham [:jgraham]]

https://tbpl.mozilla.org/?tree=Try&rev=3c54b601cd58

Comment 3

[Chris Manchester (limited bugmail, email directly)]

Comment on attachment 8467331 [details] [diff] [review]
Improve mozlog.structured argument handling

Review of attachment 8467331 [details] [diff] [review]:
-----------------------------------------------------------------

::: testing/mozbase/mozlog/tests/test_structured.py
@@ +372,5 @@
> +        self.logger.suite_start([], {})
> +        self.assert_log_equals({"action": "suite_start",
> +                                "tests": [],
> +                                "run_info": {}})
> +        self.logger.test_start(test="test1")

I think it's a little weird this test passes... it looks like this means all args to log_action functions are kwargs from the perspective of the caller, and this test will pass:

        self.logger.test_status(expected="FAIL", subtest="subtest1", test="test1", status="PASS")
        self.assert_log_equals({"action": "test_status",
                                "test": "test1",
                                "subtest": "subtest1",
                                "status": "PASS",
                                "expected": "FAIL"})

Maybe this is ok, but currently error messages are not particularly useful in cases a bad key name is passed in (the message is 'Too few arguments').

Comment 4

[James Graham [:jgraham]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/ba3b368bad0a

> I think it's a little weird this test passes... it looks like this means all
> args to log_action functions are kwargs from the perspective of the caller,
> and this test will pass:
> 
>         self.logger.test_status(expected="FAIL", subtest="subtest1",
> test="test1", status="PASS")
>         self.assert_log_equals({"action": "test_status",
>                                 "test": "test1",
>                                 "subtest": "subtest1",
>                                 "status": "PASS",
>                                 "expected": "FAIL"})
> 
> Maybe this is ok, but currently error messages are not particularly useful
> in cases a bad key name is passed in (the message is 'Too few arguments').

In [1]: def foo(a, b=1):
   ...:     print a, b
   ...:     

In [2]: foo(b=2, a=1)
1 2

This is normal python semantics. Python has different error messages though; better in this case and worse in other cases.

If we want a faster / more correct / more crazy approach here, I think we could build the wrapped function as a string and create it at runtime. The creation would only happen once per log function so we'd reduce the per-call overhead and guarantee that the function had correct python semantics. But it would be slightly crazy.

Comment 5

[Ed Morley [:emorley]]

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