Bug 210303 - Changes to shared testing JS files should not cause test failures due to console message line numbers changing
Summary: Changes to shared testing JS files should not cause test failures due to cons...
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: Tools / Tests (show other bugs)
Version: Safari Technology Preview
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Devin Rousso
URL:
Keywords: InRadar
Depends on:
Blocks:
 
Reported: 2020-04-09 13:55 PDT by Simon Fraser (smfr)
Modified: 2020-04-10 16:19 PDT (History)
21 users (show)

See Also:


Attachments
Patch (3.18 MB, patch)
2020-04-09 16:01 PDT, Devin Rousso
no flags Details | Formatted Diff | Diff
Patch (3.17 MB, patch)
2020-04-09 16:24 PDT, Devin Rousso
no flags Details | Formatted Diff | Diff
Patch (3.17 MB, patch)
2020-04-10 00:28 PDT, Devin Rousso
no flags Details | Formatted Diff | Diff
Patch (3.17 MB, patch)
2020-04-10 10:37 PDT, Devin Rousso
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Simon Fraser (smfr) 2020-04-09 13:55:05 PDT
Changing ui-helpers.js can cause other tests that include it, and which trigger console logging to fail:

--- /Volumes/Data/worker/macOS-Mojave-Release-WK2-Tests-EWS/build/layout-test-results/http/tests/adClickAttribution/anchor-tag-attributes-validation-expected.txt
+++ /Volumes/Data/worker/macOS-Mojave-Release-WK2-Tests-EWS/build/layout-test-results/http/tests/adClickAttribution/anchor-tag-attributes-validation-actual.txt
@@ -1,14 +1,14 @@
-CONSOLE MESSAGE: line 197: adcampaignid must have a non-negative value less than or equal to 63 for Ad Click Attribution.
-CONSOLE MESSAGE: line 197: adcampaignid must have a non-negative value less than or equal to 63 for Ad Click Attribution.
-CONSOLE MESSAGE: line 197: adcampaignid can not be converted to a non-negative integer which is required for Ad Click Attribution.
-CONSOLE MESSAGE: line 197: adcampaignid can not be converted to a non-negative integer which is required for Ad Click Attribution.
-CONSOLE MESSAGE: line 197: adcampaignid can not be converted to a non-negative integer which is required for Ad Click Attribution.
-CONSOLE MESSAGE: line 197: addestination could not be converted to a valid HTTP-family URL.
-CONSOLE MESSAGE: line 197: addestination could not be converted to a valid HTTP-family URL.
-CONSOLE MESSAGE: line 197: addestination could not be converted to a valid HTTP-family URL.
-CONSOLE MESSAGE: line 197: Both adcampaignid and addestination need to be set for Ad Click Attribution to work.
-CONSOLE MESSAGE: line 197: Both adcampaignid and addestination need to be set for Ad Click Attribution to work.
-CONSOLE MESSAGE: line 197: addestination can not be the same site as the current website.
+CONSOLE MESSAGE: line 207: adcampaignid must have a non-negative value less than or equal to 63 for Ad Click Attribution.
+CONSOLE MESSAGE: line 207: adcampaignid must have a non-negative value less than or equal to 63 for Ad Click Attribution.
+CONSOLE MESSAGE: line 207: adcampaignid can not be converted to a non-negative integer which is required for Ad Click Attribution.
+CONSOLE MESSAGE: line 207: adcampaignid can not be converted to a non-negative integer which is required for Ad Click Attribution.
+CONSOLE MESSAGE: line 207: adcampaignid can not be converted to a non-negative integer which is required for Ad Click Attribution.
+CONSOLE MESSAGE: line 207: addestination could not be converted to a valid HTTP-family URL.
+CONSOLE MESSAGE: line 207: addestination could not be converted to a valid HTTP-family URL.
+CONSOLE MESSAGE: line 207: addestination could not be converted to a valid HTTP-family URL.
+CONSOLE MESSAGE: line 207: Both adcampaignid and addestination need to be set for Ad Click Attribution to work.
+CONSOLE MESSAGE: line 207: Both adcampaignid and addestination need to be set for Ad Click Attribution to work.
+CONSOLE MESSAGE: line 207: addestination can not be the same site as the current website.
 Test for validity of ad click attribution attributes on anchor tags.
 
 On success, you will see a series of "PASS" messages, followed by "TEST COMPLETE".

This is annoying and we need to fix testing infrastructure to avoid it.
Comment 1 Simon Fraser (smfr) 2020-04-09 13:55:34 PDT
I propose excluding line numbers from console logs when running tests.
Comment 2 Devin Rousso 2020-04-09 14:03:49 PDT
(In reply to Simon Fraser (smfr) from comment #1)
> I propose excluding line numbers from console logs when running tests.
+1
Comment 3 Darin Adler 2020-04-09 14:11:16 PDT
Seems OK.

I’m a little unclear on what these line numbers are.

On the other hand, when writing tests it’s important the test results do give context of what is being tested, and where messages are coming from. I’ve had a really annoying time debugging tests when something is wrong, but there is no label explaining where the value came from in a sea of test results.

For example, look at this:

https://trac.webkit.org/changeset/259184/webkit/trunk/LayoutTests/editing/mac/input/firstrectforcharacterrange-plain-expected.txt

The old expected result was ... not good.
Comment 4 Simon Fraser (smfr) 2020-04-09 15:57:45 PDT
I couldn't tell what line CONSOLE MESSAGE: line 207 referred to. It's not a line in the file that I changed. So those line numbers are very mysterious.
Comment 5 Devin Rousso 2020-04-09 16:01:49 PDT
Created attachment 396021 [details]
Patch

test expected files modified using a simple regex find replace of `/CONSOLE MESSAGE: line \d+: /` with "CONSOLE MESSAGE: "
Comment 6 Simon Fraser (smfr) 2020-04-09 16:13:36 PDT
(In reply to Darin Adler from comment #3)
> Seems OK.
> 
> I’m a little unclear on what these line numbers are.
> 
> On the other hand, when writing tests it’s important the test results do
> give context of what is being tested, and where messages are coming from.
> I’ve had a really annoying time debugging tests when something is wrong, but
> there is no label explaining where the value came from in a sea of test
> results.
> 
> For example, look at this:
> 
> https://trac.webkit.org/changeset/259184/webkit/trunk/LayoutTests/editing/
> mac/input/firstrectforcharacterrange-plain-expected.txt
> 
> The old expected result was ... not good.

It's possible to remotely web-inspect WebKitTestRunner. Most easily done by making the test time out, and running WTR with --no-timeout, then you can just pick it as an inspection target from Safari. That's the easiest way to discover JS errors and debug tests.
Comment 7 Devin Rousso 2020-04-09 16:24:16 PDT
Created attachment 396023 [details]
Patch

rebase
Comment 8 Devin Rousso 2020-04-10 00:28:21 PDT
Created attachment 396060 [details]
Patch
Comment 9 Devin Rousso 2020-04-10 10:37:01 PDT
Created attachment 396100 [details]
Patch
Comment 10 EWS 2020-04-10 14:10:34 PDT
Committed r259900: <https://trac.webkit.org/changeset/259900>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 396100 [details].
Comment 11 Radar WebKit Bug Importer 2020-04-10 14:11:29 PDT
<rdar://problem/61603950>
Comment 12 Darin Adler 2020-04-10 15:18:28 PDT
I am a little sad that since we had to touch all these files anyway, we still chose to include CONSOLE on every single line. We should ask ourselves: "How would we format this if we wanted a human being to be able to read and understand it and NOT BE SHOUTED AT?" And consider tweaking the format.
Comment 13 Darin Adler 2020-04-10 15:19:07 PDT
(In reply to Simon Fraser (smfr) from comment #6)
> It's possible to remotely web-inspect WebKitTestRunner. Most easily done by
> making the test time out, and running WTR with --no-timeout, then you can
> just pick it as an inspection target from Safari. That's the easiest way to
> discover JS errors and debug tests.

Seems to not respond to my concern, though.

If the test output is good I can fix a bug without a debugging session.
Comment 14 Devin Rousso 2020-04-10 15:38:19 PDT
(In reply to Darin Adler from comment #12)
> I am a little sad that since we had to touch all these files anyway, we still chose to include CONSOLE on every single line. We should ask ourselves: "How would we format this if we wanted a human being to be able to read and understand it and NOT BE SHOUTED AT?" And consider tweaking the format.

`console.*` allow for a fully customizable string to be provided as the first argument, which is what will be logged as part of `CONSOLE ___`.  I would argue that if the message isn't helpful, then the message itself should be changed, not the format in which it was logged.  This includes console messages that come from within WebKit too.

I personally believe that if the line number is critical to understanding what the message is talking about, then the message has failed to be clear enough to be useful and should be changed.

Personally, I've been wanting to do something like this for a while, as we run into this a lot with Web Inspector whenever we change 'Source/JavaScriptCore/inspector/InjectedScriptSource.js', causing a large number of unrelated tests to start failing because the line number changed.
Comment 15 Darin Adler 2020-04-10 16:09:11 PDT
(In reply to Devin Rousso from comment #14)
> (In reply to Darin Adler from comment #12)
> > I am a little sad that since we had to touch all these files anyway, we still chose to include CONSOLE on every single line. We should ask ourselves: "How would we format this if we wanted a human being to be able to read and understand it and NOT BE SHOUTED AT?" And consider tweaking the format.
> 
> I personally believe that if the line number is critical to understanding
> what the message is talking about, then the message has failed to be clear
> enough to be useful and should be changed.

Sure.

My comment is about the remaining text "CONSOLE:" in front of every line. I agree the line number is not needed. I am not second-guessing this change, which is already done.

Why is "CONSOLE:" still needed?
Comment 16 Devin Rousso 2020-04-10 16:14:12 PDT
(In reply to Darin Adler from comment #15)
> (In reply to Devin Rousso from comment #14)
> > (In reply to Darin Adler from comment #12)
> > > I am a little sad that since we had to touch all these files anyway, we still chose to include CONSOLE on every single line. We should ask ourselves: "How would we format this if we wanted a human being to be able to read and understand it and NOT BE SHOUTED AT?" And consider tweaking the format.
> > 
> > I personally believe that if the line number is critical to understanding what the message is talking about, then the message has failed to be clear enough to be useful and should be changed.
> 
> Sure.
> 
> My comment is about the remaining text "CONSOLE:" in front of every line. I agree the line number is not needed. I am not second-guessing this change, which is already done.
> 
> Why is "CONSOLE:" still needed?

I would have it be there to help distinguish where it came from.  Other functions, such as `alert`, have their own prefixes (like "ALERT:").
Comment 17 Darin Adler 2020-04-10 16:19:53 PDT
OK. I know about these all because I originally implemented them.

I don’t like them now. While I agree we want to know where the message came from, ALL CAPITALS AT THE START OF EVERY LINE doesn’t seem like human-friendly design.