Closed Bug 1403577 Opened 7 years ago Closed 7 years ago

Limit length of logged packets

Categories

(Remote Protocol :: Marionette, enhancement)

Product:
Remote Protocol
Component:
Marionette
Version:
Version 3
Type:
enhancement
Priority:
Not set
Severity:
normal

Tracking

(firefox58 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla58
Tracking Flags:
Tracking Status
firefox58 --- fixed

People

(Reporter: ato, Assigned: ato)

References

Details

Attachments

(6 files, 1 obsolete file)

Bug 1403577 - Add utility for truncating strings.
59 bytes, text/x-review-board-request
whimboo
: review+
Details
Bug 1403577 - Use named imports.
59 bytes, text/x-review-board-request
whimboo
: review+
Details
Bug 1403577 - Rename toMsg/fromMsg to toPacket/fromPacket.
59 bytes, text/x-review-board-request
whimboo
: review+
Details
Bug 1403577 - Fix Message, Command, and Response docs.
59 bytes, text/x-review-board-request
whimboo
: review+
Details
Bug 1403577 - Associate message origin enum with Message type.
59 bytes, text/x-review-board-request
whimboo
: review+
Details
Bug 1403577 - Rename TYPE identifier to Type.
59 bytes, text/x-review-board-request
whimboo
: review+
Details 
The trace level output logging incoming and outgoing packets to
Marionette can sometimes be rather long when we send across large
chunks of data (such as Base64-encoded screenshots).

Because we don’t actually need this information exactly we should
limit the length of the logged packets.
Assignee: nobody → ato
Status: NEW → ASSIGNED
Do you plan to stripp off data from the middle of it, or the end? IMO the middle would be better.
(In reply to Henrik Skupin (:whimboo) from comment #1)
> Do you plan to stripp off data from the middle of it, or the end? IMO the
> middle would be better.

I don’t know exactly what you mean by “the middle of it”.
(In reply to Andreas Tolfsen ‹:ato› from comment #2)
> (In reply to Henrik Skupin (:whimboo) from comment #1)
> > Do you plan to stripp off data from the middle of it, or the end? IMO the
> > middle would be better.
> 
> I don’t know exactly what you mean by “the middle of it”.

With XUL we have different options in how to use the ellipsis to visualize cut out content:

1) ... visible content (beginning)
2) This is ... content (middle)
3) This is visible ... (end)

I ask because in some cases helpful information could be at the beginning and end of a message. The middle part might in most cases be not interesting.
(In reply to Henrik Skupin (:whimboo) from comment #16)

> With XUL we have different options in how to use the ellipsis to
> visualize cut out content:
> 
> 1) ... visible content (beginning)
> 2) This is ... content (middle)
> 3) This is visible ... (end)
> 
> I ask because in some cases helpful information could be at the
> beginning and end of a message. The middle part might in most
> cases be not interesting.

That seems like a possible improvement it shouldn’t be too hard
to make.  At the moment it cuts off a string at 250 characters and
appends " <...>".
Comment on attachment 8913975 [details]
Bug 1403577 - Rename toMsg/fromMsg to toPacket/fromPacket.

https://reviewboard.mozilla.org/r/185378/#review190606

::: testing/marionette/message.js:163
(Diff revision 3)
>      return "Command {id: " + this.id + ", " +
>          "name: " + JSON.stringify(this.name) + ", " +
>          "parameters: " + JSON.stringify(this.parameters) + "}";
>    }
>  
> -  static fromMsg(msg) {
> +  static fromPacket(payload) {

Lets add a documentation here too.

::: testing/marionette/message.js:317
(Diff revision 3)
> +      Response.TYPE,
> +      this.id,
> +      this.error,
> +      this.body,
> +    ];
>    toString() {

Please add an empty line above.

::: testing/marionette/message.js:323
(Diff revision 3)
>      return "Response {id: " + this.id + ", " +
>          "error: " + JSON.stringify(this.error) + ", " +
>          "body: " + JSON.stringify(this.body) + "}";
>    }
>  
> -  static fromMsg(msg) {
> +  static fromPacket(payload) {

Documentation please.
Attachment #8913975 - Flags: review?(hskupin) → review+
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review190610

I don't know the string templates that well and had to read in first. So forgive some maybe silly questions.

::: commit-message-19f36:6
(Diff revision 2)
> +Bug 1403577 - Add utility for truncating strings. r?whimboo
> +
> +Introduces a utility that truncates strings in potentially arbitrary
> +object structures.  This allows JSON structures that contain long
> +strings to be shortened with an " <...>" appendix for pretty logging
> +when data integrity is not a vital concern.

As mentioned in my last comment, truncating in the middle ensure that content from the end will also be visible. In the past this has been turned out pretty helpful.

::: testing/marionette/fmt.js:1
(Diff revision 2)
> +/* This Source Code Form is subject to the terms of the Mozilla Public

I would give that file a full and meaningful name.

::: testing/marionette/fmt.js:9
(Diff revision 2)
> +
> +"use strict";
> +
> +this.EXPORTED_SYMBOLS = ["truncate"];
> +
> +const STRING_LIMIT = 250;  // characters

I find `MAX_STRING_LENGTH` better understandable. It would also make the inline comment obsolete.

Maybe add that the remaining 6 charactors are already counted in for the `<...>`. Btw. there is the ellipse sign you can use here, so we can safe 2 more chars!

::: testing/marionette/fmt.js:28
(Diff revision 2)
> + * </code></pre>
> + *
> + * Functions named <code>toJSON</code> or <code>toString</code>
> + * on objects will be called.
> + */
> +function truncate(ss, ...values) {

s/ss/string to make it clearer, and to avoid acronyms from a bad moments in history.

Also the examples I found say `keys` and not `values`. What's correct here?

::: testing/marionette/fmt.js:28
(Diff revision 2)
> + * </code></pre>
> + *
> + * Functions named <code>toJSON</code> or <code>toString</code>
> + * on objects will be called.
> + */
> +function truncate(ss, ...values) {

Will it also work with pprint? Or is only one template allowed?

::: testing/marionette/fmt.js:67
(Diff revision 2)
> +  }
> +
> +  let res = [];
> +  for (let i = 0; i < ss.length; ++i) {
> +    res.push(ss[i]);
> +    if (i < values.length) {

Can this length ever be different than the one from the strings?

::: testing/marionette/test_fmt.js:43
(Diff revision 2)
> +  run_next_test();
> +});
> +
> +add_test(function test_truncate_array() {
> +  equal(truncate`${["foo"]}`, JSON.stringify(["foo"]));
> +  equal(truncate`${"foo"} ${["bar"]}`, `foo ${JSON.stringify(["bar"])}`);

So what about long strings inside arrays? We truncate those too, right?

::: testing/marionette/test_fmt.js:51
(Diff revision 2)
> +
> +add_test(function test_truncate_object() {
> +  equal(truncate`${{}}`, JSON.stringify({}));
> +  equal(truncate`${{foo: "bar"}}`, JSON.stringify({foo: "bar"}));
> +  equal(truncate`${{foo: ["bar"]}}`, JSON.stringify({foo: ["bar"]}));
> +  equal(truncate`${{foo: ["bar", {baz: 42}]}}`, JSON.stringify({foo: ["bar", {baz: 42}]}));

Same as above.
Attachment #8913973 - Flags: review?(hskupin) → review-
Comment on attachment 8913977 [details]
Bug 1403577 - Truncate string representations of Command and Response.

https://reviewboard.mozilla.org/r/185382/#review190636

::: testing/marionette/message.js:170
(Diff revision 3)
> -
> -  toString() {
> -    return "Command {id: " + this.id + ", " +
> -        "name: " + JSON.stringify(this.name) + ", " +
> -        "parameters: " + JSON.stringify(this.parameters) + "}";
>    }

It's great to see such code gone!
Attachment #8913977 - Flags: review?(hskupin) → review+
Comment on attachment 8913978 [details]
Bug 1403577 - Associate message origin enum with Message type.

https://reviewboard.mozilla.org/r/185384/#review190638

::: testing/marionette/server.js:670
(Diff revision 3)
>    sendRaw(payload) {
>      this.conn.send(payload);
>    }
>  
>    log_(msg) {
> -    let a = (msg.origin == MessageOrigin.Client ? " -> " : " <- ");
> +    let dir = (msg.origin == Message.Origin.Client ? "->" : "<-");

To avoid the tenary operator we could do `["->", "<-"][msg.origin]´.
Attachment #8913978 - Flags: review?(hskupin) → review+
Comment on attachment 8913979 [details]
Bug 1403577 - Rename TYPE identifier to Type.

https://reviewboard.mozilla.org/r/185386/#review190640
Attachment #8913979 - Flags: review?(hskupin) → review+
Comment on attachment 8913976 [details]
Bug 1403577 - Fix Message, Command, and Response docs.

https://reviewboard.mozilla.org/r/185380/#review190686
Attachment #8913976 - Flags: review?(hskupin) → review+
Comment on attachment 8913974 [details]
Bug 1403577 - Use named imports.

https://reviewboard.mozilla.org/r/185376/#review190688
Attachment #8913974 - Flags: review?(hskupin) → review+
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review190610

> As mentioned in my last comment, truncating in the middle ensure that content from the end will also be visible. In the past this has been turned out pretty helpful.

Fixed.

> I would give that file a full and meaningful name.

‘fmt’ is a fine name for a module that does string
formatting.  C.f. https://en.wikipedia.org/wiki/Fmt_(Unix) and
https://golang.org/pkg/fmt/.

> I find `MAX_STRING_LENGTH` better understandable. It would also make the inline comment obsolete.
> 
> Maybe add that the remaining 6 charactors are already counted in for the `<...>`. Btw. there is the ellipse sign you can use here, so we can safe 2 more chars!

Fixed the constant name.

We can’t use the ellipse symbol because UTF-8 isn’t supported in
Mozilla .js source files or in the Windows terminal.

> s/ss/string to make it clearer, and to avoid acronyms from a bad moments in history.
> 
> Also the examples I found say `keys` and not `values`. What's correct here?

> s/ss/string to make it clearer, and to avoid acronyms from a bad
> moments in history.

ss isn’t a string, but a sequence of strings.  I want to refer you
to https://www.lysator.liu.se/c/pikestyle.html regarding variable
naming.  I don’t thing "string" (or "strings") adds any particular
semantic value here.

> Also the examples I found say keys and not values. What's correct
> here?

Not sure what examples you are referring to but the fields are
definitely some form of value, not keys for lookup in some table.

> Will it also work with pprint? Or is only one template allowed?

Will what also work with pprint?

> Can this length ever be different than the one from the strings?

Yes, if no values/fields are given, i.e. there are no ${foo}’s in
the string, values.length will be 0.  We only walk the values we
want to insert into res.

> So what about long strings inside arrays? We truncate those too, right?

We truncate all strings we encounter.  obj.map(walk) in the truncate
function ensures this.
Comment on attachment 8913975 [details]
Bug 1403577 - Rename toMsg/fromMsg to toPacket/fromPacket.

https://reviewboard.mozilla.org/r/185378/#review190606

> Lets add a documentation here too.

Fixed.

> Please add an empty line above.

This was a mistake from my rebasing.  Fixed.

> Documentation please.

Fixed.
Attachment #8913977 - Attachment is obsolete: true
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review190610

> ‘fmt’ is a fine name for a module that does string
> formatting.  C.f. https://en.wikipedia.org/wiki/Fmt_(Unix) and
> https://golang.org/pkg/fmt/.

Those are all links to sources outside of our tree. In general it is good practice to use what is preferred in our code base.

But if you think it's fine, then just drop this issue.

> Fixed the constant name.
> 
> We can’t use the ellipse symbol because UTF-8 isn’t supported in
> Mozilla .js source files or in the Windows terminal.

That's sad to hear. Especially for the problem on Windows.

> > s/ss/string to make it clearer, and to avoid acronyms from a bad
> > moments in history.
> 
> ss isn’t a string, but a sequence of strings.  I want to refer you
> to https://www.lysator.liu.se/c/pikestyle.html regarding variable
> naming.  I don’t thing "string" (or "strings") adds any particular
> semantic value here.
> 
> > Also the examples I found say keys and not values. What's correct
> > here?
> 
> Not sure what examples you are referring to but the fields are
> definitely some form of value, not keys for lookup in some table.

> ss isn’t a string, but a sequence of strings.  I want to refer you
to https://www.lysator.liu.se/c/pikestyle.html regarding variable
naming.  I don’t thing "string" (or "strings") adds any particular
semantic value here.

Sorry, I meant 'strings' here. So 'ss' adds a semantic value and makes it directly clear for everyone what this parameter is used for? I would be ok with a name like 'ss' as a local variable inside the method, but as parameter it doesn't say anything. Also because parameters are not documented.

> Will what also work with pprint?

A combination of truncate and pprint. Or is it mutually exclusive?

> We truncate all strings we encounter.  obj.map(walk) in the truncate
> function ensures this.

Can you add a testcase for that please?
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review190610

> Those are all links to sources outside of our tree. In general it is good practice to use what is preferred in our code base.
> 
> But if you think it's fine, then just drop this issue.

You haven’t come up with any reasonable concrete proposal, so
unless you do I’m inclined to drop this issue.  Code is mutable,
which means we can change this at will.

> That's sad to hear. Especially for the problem on Windows.

Yes, this is incidentally why we reverted from ← and → to <- and
-> for logging packets in geckodriver.
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review190610

> You haven’t come up with any reasonable concrete proposal, so
> unless you do I’m inclined to drop this issue.  Code is mutable,
> which means we can change this at will.

I think your naming skills are quite good and you don't need a proposal from me. But anyway, what about `format.js`?
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review190610

> I think your naming skills are quite good and you don't need a proposal from me. But anyway, what about `format.js`?

I’m fine with that name too.  const {truncate} = Cu.import("marionette/format.js", {}) looks quite all right in my opinion.

> A combination of truncate and pprint. Or is it mutually exclusive?

It shouldn’t cause any problems. pprint prettifies objects of
various types, whereas truncate only manipulates strings.  You will
obviously get different results depending on which you call first,
but for as long as they don’t end up recursively calling eachother
it should be fine.
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review190610

> > ss isn’t a string, but a sequence of strings.  I want to refer you
> to https://www.lysator.liu.se/c/pikestyle.html regarding variable
> naming.  I don’t thing "string" (or "strings") adds any particular
> semantic value here.
> 
> Sorry, I meant 'strings' here. So 'ss' adds a semantic value and makes it directly clear for everyone what this parameter is used for? I would be ok with a name like 'ss' as a local variable inside the method, but as parameter it doesn't say anything. Also because parameters are not documented.

I have renamed s/ss/strings/ because I don’t think a prolonged
debate on variable naming is worth spending time on.

> Can you add a testcase for that please?

Done.

> Same as above.

And done.
Something went wrong with my last review. The comments on an interdiff have not been published somehow. I will see how to get those published.
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review191808

::: testing/marionette/fmt.js:9
(Diff revisions 2 - 3)
>  
>  "use strict";
>  
>  this.EXPORTED_SYMBOLS = ["truncate"];
>  
> -const STRING_LIMIT = 250;  // characters
> +const MAX_STRING_LENGTH = 250;

Given that we cut in the middle now this constant should be 249.
Attachment #8913973 - Flags: review?(hskupin) → review-
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review192138

Lets address the last comment. Otherwise it's fine.
Attachment #8913973 - Flags: review- → review+
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review191808

> Given that we cut in the middle now this constant should be 249.

This is just an arbitrary number.  It doesn’t matter what it is.

Because we only truncate strings if they are greater-than
MAX_STRING_LENGTH, not greater-than-or-equal-to, obj.length will
always be of sufficient length that we don’t have to worry about
obj.substring(n, (MAX_STRING_LENGTH / 2)) for s1 and s2 overlapping.

Technically we don’t have to use (MAX_STRING_LENGTH / 2) at all in
that equation but could pick a random number
<= ((MAX_STRING_LENGTH / 2) - 1).
Attachment #8913973 - Flags: review+ → review?(hskupin)
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review191808

> This is just an arbitrary number.  It doesn’t matter what it is.
> 
> Because we only truncate strings if they are greater-than
> MAX_STRING_LENGTH, not greater-than-or-equal-to, obj.length will
> always be of sufficient length that we don’t have to worry about
> obj.substring(n, (MAX_STRING_LENGTH / 2)) for s1 and s2 overlapping.
> 
> Technically we don’t have to use (MAX_STRING_LENGTH / 2) at all in
> that equation but could pick a random number
> <= ((MAX_STRING_LENGTH / 2) - 1).

I thought that you made it explicit to be at maximum 256 (byte) in length. That's why my comment.
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review193996

::: testing/marionette/format.js:48
(Diff revision 4)
> +
> +      case "[object String]":
> +        if (obj.length > MAX_STRING_LENGTH) {
> +          let s1 = obj.substring(0, (MAX_STRING_LENGTH / 2));
> +          let s2 = obj.substring(obj.length - (MAX_STRING_LENGTH / 2));
> +          return `${s1} <...> ${s2}`;

I just checked other code which is using continuation and none of them include the <> signs. Maybe we can just follow the general style and remove it too?
Attachment #8913973 - Flags: review?(hskupin) → review+
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review193996

> I just checked other code which is using continuation and none of them include the <> signs. Maybe we can just follow the general style and remove it too?

Yes, sure.  Fixed.
Comment on attachment 8913973 [details]
Bug 1403577 - Add utility for truncating strings.

https://reviewboard.mozilla.org/r/185374/#review191808

> I thought that you made it explicit to be at maximum 256 (byte) in length. That's why my comment.

Oh I see the confusion.  (250 + " <...> ".length) - 1 = 256.

I think your concern would be valid if we reduced MAX_STRING_LENGTH
to a fairly low number like 6 or 12.
Pushed by atolfsen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/df3e0cc4a9bf
Add utility for truncating strings. r=whimboo
https://hg.mozilla.org/integration/autoland/rev/2fe618b2b660
Rename toMsg/fromMsg to toPacket/fromPacket. r=whimboo
https://hg.mozilla.org/integration/autoland/rev/f5c5cc198dda
Associate message origin enum with Message type. r=whimboo
https://hg.mozilla.org/integration/autoland/rev/1f2fb2cb9f9c
Rename TYPE identifier to Type. r=whimboo
https://hg.mozilla.org/integration/autoland/rev/e982da33966d
Fix Message, Command, and Response docs. r=whimboo
https://hg.mozilla.org/integration/autoland/rev/39eda882de4f
Use named imports. r=whimboo
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: