Bug 206542

Summary: webkitpy: Make logging during ImageDiff crashes accurate
Product: WebKit Reporter: Jonathan Bedard <jbedard>
Component: Tools / TestsAssignee: Jonathan Bedard <jbedard>
Status: RESOLVED FIXED    
Severity: Normal CC: aakash_jain, ap, commit-queue, ews-watchlist, glenn, slewis, webkit-bug-importer
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
Attachments:
Description Flags
Patch
none
Patch none

Description Jonathan Bedard 2020-01-21 10:50:50 PST
Part of trying to debug various failures with ImageDiff, such as  https://build.webkit.org/builders/Apple-Catalina-Release-WK2-Tests/builds/2243. The logging when ImageDiff crashes is not accurate.
Comment 1 Jonathan Bedard 2020-01-21 10:52:17 PST
Created attachment 388322 [details]
Patch
Comment 2 Aakash Jain 2020-01-21 13:37:08 PST
(In reply to Jonathan Bedard from comment #0)
> The logging when ImageDiff crashes is not accurate.
Can you provide some example/explanation?
Comment 3 Jonathan Bedard 2020-01-21 13:43:58 PST
(In reply to Aakash Jain from comment #2)
> (In reply to Jonathan Bedard from comment #0)
> > The logging when ImageDiff crashes is not accurate.
> Can you provide some example/explanation?

ImageDiff uses the same process runner that WebKitTestRunner uses. The log messages for this process runner were designed for WebKitTestRunner, but they aren't accurate when ImageDiff crashes. Take a look at https://build.webkit.org/builders/Apple-Catalina-Release-WK2-Tests/builds/2243/steps/layout-test/logs/stdio and what's printed right after 'ImageDiff crashed'. The log reads 'This test marked as a crash because of a broken pipe when writing to stdin of the server process.', that's just not correct. The test will be marked as an Image failure, not a crash.
Comment 4 Aakash Jain 2020-01-22 07:37:38 PST
(In reply to Jonathan Bedard from comment #3)
> The log reads 'This test marked as a crash because of a broken
> pipe when writing to stdin of the server process.', that's just not correct.
> The test will be marked as an Image failure, not a crash.
So what would the new log look like?

Are we only changing the logs or is there any behavior change as well?
Comment 5 Jonathan Bedard 2020-01-22 07:51:23 PST
(In reply to Aakash Jain from comment #4)
> (In reply to Jonathan Bedard from comment #3)
> > The log reads 'This test marked as a crash because of a broken
> > pipe when writing to stdin of the server process.', that's just not correct.
> > The test will be marked as an Image failure, not a crash.
> So what would the new log look like?
> 
> Are we only changing the logs or is there any behavior change as well?

New log here would read:

Test marked as failed, ImageDiff crashed because of a broken pipe when writing to stdin of the server process.

There are not behavior changes. Generally, this allows us to swap 'This test marked as a crash' for anything. At the moment, the only thing we're swapping it with is 'Test marked as failed, ImageDiff crashed' for ImageDiff
Comment 6 Aakash Jain 2020-01-22 08:20:36 PST
Comment on attachment 388322 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=388322&action=review

> Tools/ChangeLog:10
> +        With an Image failure. The owner of a ServerProcess should be able

Nit: 'With' -> 'with'

> Tools/ChangeLog:11
> +        To customize this error message.

Nit: 'To' -> 'to'

> Tools/Scripts/webkitpy/port/port_testcase.py:281
> +        def make_proc(port, nm, cmd, env, crash_message=None):

why is make_proc being modified?

> Tools/Scripts/webkitpy/port/server_process.py:68
> +        self._crash_message = crash_message or 'This test marked as a crash'

Shouldn't this go in crash_message default value of this function?
Comment 7 Jonathan Bedard 2020-01-22 08:51:02 PST
Comment on attachment 388322 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=388322&action=review

>> Tools/Scripts/webkitpy/port/port_testcase.py:281
>> +        def make_proc(port, nm, cmd, env, crash_message=None):
> 
> why is make_proc being modified?

This file is use for unit testing. make_proc is set as the _server_process_constructor, so it needs to accept crash_message since image_diff.py passes it.

>> Tools/Scripts/webkitpy/port/server_process.py:68
>> +        self._crash_message = crash_message or 'This test marked as a crash'
> 
> Shouldn't this go in crash_message default value of this function?

No, that messes up default values in classes which inherit from this one.
Comment 8 Jonathan Bedard 2020-01-22 09:28:05 PST
Created attachment 388430 [details]
Patch
Comment 9 WebKit Commit Bot 2020-01-22 10:32:25 PST
Comment on attachment 388430 [details]
Patch

Rejecting attachment 388430 [details] from commit-queue.

Failed to run "['/Volumes/Data/EWS/WebKit/Tools/Scripts/webkit-patch', '--status-host=webkit-queues.webkit.org', '--bot-id=webkit-cq-02', 'land-attachment', '--force-clean', '--non-interactive', '--parent-command=commit-queue', 388430, '--port=mac']" exit_code: 2 cwd: /Volumes/Data/EWS/WebKit

Logging in as commit-queue@webkit.org...
Fetching: https://bugs.webkit.org/attachment.cgi?id=388430&action=edit
Fetching: https://bugs.webkit.org/show_bug.cgi?id=206542&ctype=xml&excludefield=attachmentdata
Processing 1 patch from 1 bug.
Updating working directory
Processing patch 388430 from bug 206542.
Fetching: https://bugs.webkit.org/attachment.cgi?id=388430
Failed to run "['git', 'svn', 'dcommit', '--rmdir']" exit_code: 1 cwd: /Volumes/Data/EWS/WebKit

Committing to http://svn.webkit.org/repository/webkit/trunk ...
Authentication realm: <http://svn.webkit.org:80> Mac OS Forge
Password for 'buildbot': 
Authentication realm: <http://svn.webkit.org:80> Mac OS Forge
Username: Use of uninitialized value $ret in chomp at /Applications/Xcode.app/Contents/Developer/usr/share/git-core/perl/Git.pm line 596.
Use of uninitialized value in concatenation (.) or string at /Applications/Xcode.app/Contents/Developer/usr/share/git-core/perl/Git/SVN/Prompt.pm line 20.
Password for '': 
Authentication realm: <http://svn.webkit.org:80> Mac OS Forge
Username: Use of uninitialized value $ret in chomp at /Applications/Xcode.app/Contents/Developer/usr/share/git-core/perl/Git.pm line 596.
Use of uninitialized value in concatenation (.) or string at /Applications/Xcode.app/Contents/Developer/usr/share/git-core/perl/Git/SVN/Prompt.pm line 20.
Password for '': 

ERROR from SVN:
Authentication failed: No more credentials or we tried too many times.
Authentication failed
W: 7d7995cb0a3630e79821782749e5354039b6eb98 and refs/remotes/origin/master differ, using rebase:
:040000 040000 b990f9a9fc2a5c55979c35f707b3c1b7dab82fbe 46931ca19b994042b0685b510bddb4e4d99ae614 M	Tools
Current branch master is up to date.
ERROR: Not all changes have been committed into SVN, however the committed
ones (if any) seem to be successfully integrated into the working tree.
Please see the above messages for details.


Failed to run "['git', 'svn', 'dcommit', '--rmdir']" exit_code: 1 cwd: /Volumes/Data/EWS/WebKit

Committing to http://svn.webkit.org/repository/webkit/trunk ...
Authentication realm: <http://svn.webkit.org:80> Mac OS Forge
Password for 'buildbot': 
Authentication realm: <http://svn.webkit.org:80> Mac OS Forge
Username: Use of uninitialized value $ret in chomp at /Applications/Xcode.app/Contents/Developer/usr/share/git-core/perl/Git.pm line 596.
Use of uninitialized value in concatenation (.) or string at /Applications/Xcode.app/Contents/Developer/usr/share/git-core/perl/Git/SVN/Prompt.pm line 20.
Password for '': 
Authentication realm: <http://svn.webkit.org:80> Mac OS Forge
Username: Use of uninitialized value $ret in chomp at /Applications/Xcode.app/Contents/Developer/usr/share/git-core/perl/Git.pm line 596.
Use of uninitialized value in concatenation (.) or string at /Applications/Xcode.app/Contents/Developer/usr/share/git-core/perl/Git/SVN/Prompt.pm line 20.
Password for '': 

ERROR from SVN:
Authentication failed: No more credentials or we tried too many times.
Authentication failed
W: 7d7995cb0a3630e79821782749e5354039b6eb98 and refs/remotes/origin/master differ, using rebase:
:040000 040000 b990f9a9fc2a5c55979c35f707b3c1b7dab82fbe 46931ca19b994042b0685b510bddb4e4d99ae614 M	Tools
Current branch master is up to date.
ERROR: Not all changes have been committed into SVN, however the committed
ones (if any) seem to be successfully integrated into the working tree.
Please see the above messages for details.


Failed to run "['git', 'svn', 'dcommit', '--rmdir']" exit_code: 1 cwd: /Volumes/Data/EWS/WebKit
Updating OpenSource
From git://git.webkit.org/WebKit
   3cf18bc55f0..29ac667b9f1  master     -> origin/master
Partial-rebuilding .git/svn/refs/remotes/origin/master/.rev_map.268f45cc-cd09-0410-ab3c-d52691b4dbfc ...
Currently at 254927 = 3cf18bc55f006c19b0ab50af977b8c94166859b6
r254928 = 29ac667b9f17a47576cb1d74c1458f039261efe1
Done rebuilding .git/svn/refs/remotes/origin/master/.rev_map.268f45cc-cd09-0410-ab3c-d52691b4dbfc
First, rewinding head to replay your work on top of it...
Fast-forwarded master to refs/remotes/origin/master.

Full output: https://webkit-queues.webkit.org/results/13309824
Comment 10 WebKit Commit Bot 2020-01-22 10:55:51 PST
Comment on attachment 388430 [details]
Patch

Clearing flags on attachment: 388430

Committed r254929: <https://trac.webkit.org/changeset/254929>
Comment 11 WebKit Commit Bot 2020-01-22 10:55:53 PST
All reviewed patches have been landed.  Closing bug.
Comment 12 Radar WebKit Bug Importer 2020-01-22 10:56:24 PST
<rdar://problem/58802650>