1324929 - Server side logs don't parse backtrace properly

Status: RESOLVED FIXED

(DevTools :: Console, defect)

Description

[Florian Apolloner]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:50.0) Gecko/20100101 Firefox/50.0
Build ID: 20161213211510

Steps to reproduce:

I followed the https://craig.is/writing/chrome-logger/techspecs spec and sent a backtrace like "somefile.py : 25"


Actual results:

The devtools only showed "somefile.py :" instead of properly displaying line & number. This at least seems to be due to a bug in http://searchfox.org/mozilla-central/source/devtools/shared/webconsole/server-logger.js#325-339 an easier implementation could look like this: https://gist.github.com/apollo13/159529a5366ed2c0d8b66223a0541695


Expected results:

devtools should have shown "somefile.py : 25"

Comment 1

[Florian Apolloner]

Attachment: properly parse backtrace

Comment 2

[Florian Apolloner]

(In reply to Florian Apolloner from comment #1)
> Created attachment 8820684 [details] [diff] [review]
> properly parse backtrace

Attached is a simple first patch which fixes the issue. I am wondering if we want to be lenient with the data we accept or if we want to force whitespace between the filename and the double colon. If we want to force a single whitespace we can drop the non-greedy flag on the regex and prevent backtracking.

Comment 3

[Nicolas Chevobbe [:nchevobbe]]

As far as I know, we're following specs from https://craig.is/writing/chrome-logger/techspecs , in which it appears that we expect something like '/path/to/file.py : 25', i.e. with single whitespace before and after the double colon.

Comment 4

[Florian Apolloner]

Attachment: bug1324929_2.patch

Comment 5

[Alexandre Poirot [:ochameau]]

Comment on attachment 8820708 [details] [diff] [review]
bug1324929_2.patch

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

Thanks Florian, I think we can better test that and ensure there is not some other edge cases.

::: devtools/shared/webconsole/test/unit/test_server_logger.js
@@ +9,5 @@
> +// bug1324929
> +function run_test() {
> +  deepEqual(parseBacktrace('somefile.py : 25'), {url: 'somefile.py', line: 25});
> +  equal(parseBacktrace('somefile.py'), 'somefile.py');
> +}

It would be better to test from end to end by contributing to this test instead:
http://searchfox.org/mozilla-central/source/devtools/client/webconsole/test/browser_console_server_logging.js

waitForMessages also expects a "stacktrace" attributes that you can use to verify that the stack being displayed is correct:
http://searchfox.org/mozilla-central/source/devtools/client/webconsole/test/browser_console.js#90

You may want to also tweak devtools/client/webconsole/test/test-console-server-logging.sjs
in order to test various scenarios where the regexp matches or not and assert the finale behavior in the UI.

Comment 6

[Florian Apolloner]

Attachment: bug1324929_3.patch

Comment 7

[Florian Apolloner]

@Alexandre: I couldn't test for the stackTrace since it was always empty, I think source is the correct thing I should test against.

Comment 8

[Alexandre Poirot [:ochameau]]

Comment on attachment 8820761 [details] [diff] [review]
bug1324929_3.patch

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

Thanks Florian, I'll submit your patch to try to run tests once you addressed the last comments.
Then, if green, we will ship your tweaks!

::: devtools/shared/webconsole/server-logger.js
@@ +491,5 @@
> +  if (!backtrace) {
> +    return null;
> +  }
> +
> +  let result = backtrace.match(/^(.+)\s:\s(\d+)$/);

It is not very explicit that spaces around ':' are mandatory,
so please use \s*:\s* and tweak tests accordingly.
(I'm afraid honza already provided libraries depending on this behavior)

@@ +493,5 @@
> +  }
> +
> +  let result = backtrace.match(/^(.+)\s:\s(\d+)$/);
> +  if (!result || result.length != 3) {
> +    return backtrace;

It looks like even if we return the string as-is, the UI ends up displaying "(unknown)". So what about returning { url: backtrace, line: -1 } or null when the regexp fails?

::: devtools/shared/webconsole/test/unit/test_server_logger.js
@@ +9,5 @@
> +// bug1324929
> +function run_test() {
> +  deepEqual(parseBacktrace('somefile.py : 25'), {url: 'somefile.py', line: 25});
> +  equal(parseBacktrace('somefile.py'), 'somefile.py');
> +}

I don't see much value in this test, so please rip it off in favor of your tweaks made to browser_console_server_logging.js.

Comment 9

[Florian Apolloner]

(In reply to Alexandre Poirot [:ochameau] from comment #8)
> It is not very explicit that spaces around ':' are mandatory,
> so please use \s*:\s* and tweak tests accordingly.

Ok, this is what I had initially, will revert to that.

> It looks like even if we return the string as-is, the UI ends up displaying
> "(unknown)". So what about returning { url: backtrace, line: -1 } or null
> when the regexp fails?

Will test and then see what I like more (probably the null variant), I just assumed that you added that with a reason initially.

> I don't see much value in this test, so please rip it off in favor of your
> tweaks made to browser_console_server_logging.js.

Ok.

Comment 10

[Florian Apolloner]

Attachment: bug1324929_4.patch

Comment 11

[Alexandre Poirot [:ochameau]]

Comment on attachment 8821158 [details] [diff] [review]
bug1324929_4.patch

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

Sorry for the delay, I was off during the end of year.
Looks good now, just miss a single space.
I just launched the tests against your patch.

::: devtools/shared/webconsole/server-logger.js
@@ +493,5 @@
> +  }
> +
> +  let result = backtrace.match(/^(.+?)\s*:\s*(\d+)$/);
> +  if (!result || result.length != 3) {
> +    return { url: backtrace};

You miss a space before the closing brace: `backtrace };`

Comment 12

[Alexandre Poirot [:ochameau]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=d8a8298b8b77

Comment 13

[Florian Apolloner]

Attachment: bug1324929_5.patch

Ok, uploaded a new patch which also fixes the eslint warning -- tests/build seems to fail, I cannot figure out what though.

Comment 14

[Alexandre Poirot [:ochameau]]

I forgot added the test file while pushing to tests. Here is a valid one:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=092ebceaae7aaccdf2034cf6d9d78256ac8193fe

It is still running, but so far, it only reports the parseInt() usage you already fixed.

Comment 15

[Alexandre Poirot [:ochameau]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/3535ad342933572ba2c93f056a9cdb44a085a6cf
Bug 1324929 - Accept ':' between url and line number in server side logs backtraces. r=ochameau

Comment 16

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/3535ad342933