run-webkit-tests hangs when WebCore tries to log too much

• Component: Tools / Tests
• Status: RESOLVED FIXED

[Eric Seidel (no email)]

run-webkit-tests hangs when WebCore tries to log too much

Just try adding a printf() to some common piece of code and running DumpRenderTree.  Eventually the pipe buffer will fill and the write() call inside that printf will block!

Of course what makes this extra annoying is that run-webkit-tests doesn't show you any log messages anyway, but that's bug 15742.

[David Kilzer (:ddkilzer)]

I have a fix for this somewhere.  Will try to dig it up.

[David Kilzer (:ddkilzer)]

Is this fixed by r30881 and r30889?  See Bug 15742 Comment #1.

[Shinichiro Hamaji]

Created attachment 35030 [details]
Patch v1


---
 2 files changed, 46 insertions(+), 23 deletions(-)

[Shinichiro Hamaji]

I'm not sure if my issue is just as same as the original bug. My case happens when WebCore outputs many stderr and write(2) is blocked. As we didn't read stderr at all until we saw EOF, the run-webkit-tests hanged. This patch would fix this issue.

[Eric Seidel (no email)]

I think you'll want Darin Adler or David Kilzer or someone with mad-perl skillz to look at this.

[David Kilzer (:ddkilzer)]

Comment on attachment 35030 [details]
Patch v1

I do think the original issue may have been blocked write(2) calls due to too much STDERR output.  Do you have an easy way to reproduce this?  Can you just add a "fprintf(stderr, "Blah\n");" to a function in WebKit that's called a lot to see the bad behavior?

Overall, this change looks good, but I have a couple of concerns.

> @@ -1984,14 +1985,16 @@ sub readFromDumpToolWithTimer(*;$)
>              last;
>          }
>  
> -        my $line = readline($fh);
> -        if (!defined($line)) {
> +        # Once we've seen the EOF, we must not read anymore.
> +        my $lineIn = readline($fhIn) unless $haveSeenEof;
> +        my $lineError = readline($fhError);

It's an interesting strategy to read a line of STDERR with a line of STDOUT from DumpRenderTree, but what guarantees that all of STDERR is read before going to the next test?  Would reading all STDERR each time work as well?

    my $lineError = <$fhError>;

> @@ -2001,20 +2004,29 @@ sub readFromDumpToolWithTimer(*;$)
>          }
>  
>          $timeOfLastSuccessfulRead = time;
> -        
> -        if (!$haveSeenContentType && $line =~ /^Content-Type: (\S+)$/) {
> -            $mimeType = $1;
> -            $haveSeenContentType = 1;
> -            next;
> +
> +        if (defined($lineIn)) {
> +            if (!$haveSeenContentType && $lineIn =~ /^Content-Type: (\S+)$/) {
> +                $mimeType = $1;
> +                $haveSeenContentType = 1;
> +                next;
> +            }
> +
> +            if ($lineIn =~ /#EOF/) {
> +                $haveSeenEof = 1;
> +                next;
> +            }
> +
> +            push @output, $lineIn;
>          }
> -        last  if ($line =~ /#EOF/);
> -        
> -        push @output, $line;
> +        push @error, $lineError if defined($lineError);
>      }

If any STDERR is printed at the same time as the "Content-Type" line or the "#EOF" line, it appears that whatever is in $lineError will be discarded.  I think the logic here should be restructured to use if () {} elif () {} else {} within if (defined($lineIn)) so that $lineError always gets appended to @error if it's defined.

r- to address the above issues.

[David Kilzer (:ddkilzer)]

(In reply to comment #6)
> It's an interesting strategy to read a line of STDERR with a line of STDOUT
> from DumpRenderTree, but what guarantees that all of STDERR is read before
> going to the next test?  Would reading all STDERR each time work as well?
> 
>     my $lineError = <$fhError>;

Of course, that should be:

    my @lineError = <$fhError>;

Other uses of $lineError would then have to be updated to use @lineError instead.

[Shinichiro Hamaji]

(In reply to comment #6)
> (From update of attachment 35030 [details])
> I do think the original issue may have been blocked write(2) calls due to too
> much STDERR output.  Do you have an easy way to reproduce this?  Can you just
> add a "fprintf(stderr, "Blah\n");" to a function in WebKit that's called a lot
> to see the bad behavior?

Yeah, the only way to reproduce the bug is the way you mentioned. Specifically, I've added showTree(newChild) into rendering/CounterNode.cpp:108 to see the behavior of CSS counter and felt this bug is annoying.

> It's an interesting strategy to read a line of STDERR with a line of STDOUT
> from DumpRenderTree, but what guarantees that all of STDERR is read before
> going to the next test?  Would reading all STDERR each time work as well?

I misunderstood the behavior of DumpRenderTree here. It outputs #EOF even for stderr. So, the best way to ensure that we've read all stderr is checking #EOF in stderr just like my previous patch was doing for stdout.

> If any STDERR is printed at the same time as the "Content-Type" line or the
> "#EOF" line, it appears that whatever is in $lineError will be discarded.  I
> think the logic here should be restructured to use if () {} elif () {} else {}
> within if (defined($lineIn)) so that $lineError always gets appended to @error
> if it's defined.

Oops. I've fixed this as you said.

I've updated my patch and I checked that I was seeing all stderrs of each test cases properly by adding fpritnf into the beginning and ending of DumpRenderTree.

[Shinichiro Hamaji]

Created attachment 35086 [details]
Patch v2


---
 2 files changed, 51 insertions(+), 25 deletions(-)

[Shinichiro Hamaji]

> Yeah, the only way to reproduce the bug is the way you mentioned. 

I meant "the only way to reproduce the bug *may be* the way you mentioned."

I could be wrong.

[David Kilzer (:ddkilzer)]

Comment on attachment 35086 [details]
Patch v2

> +    my $actualRead = readFromDumpToolWithTimer(IN, ERROR);

Now that $errorRead doesn't exist, it might be nice to rename this to $readResults, for example.

> +            if ($haveSeenEofIn && $haveSeenEofError) {
>                  last;
>              }

This could be written in a single line as:

    last if $haveSeenEofIn and $haveSeenEofError;

Neither of the above two changes are required, though.

r=me!

[Shinichiro Hamaji]

Created attachment 35092 [details]
Patch v3


---
 2 files changed, 52 insertions(+), 28 deletions(-)

[Shinichiro Hamaji]

David, thanks for the review! I did the fixes you mentioned.

[David Kilzer (:ddkilzer)]

Comment on attachment 35092 [details]
Patch v3

Great!  r=me!

[Eric Seidel (no email)]

Comment on attachment 35092 [details]
Patch v3

Shinichiro doesn't have his commit bit yet, so cq+.

[Eric Seidel (no email)]

Comment on attachment 35092 [details]
Patch v3

Rejecting patch 35092 from commit-queue.  This patch will require manual commit.

WebKitTools/Scripts/build-webkit failed with exit code 1

[David Kilzer (:ddkilzer)]

Comment on attachment 35092 [details]
Patch v3

Clearing flags on attachment: 35092

Committed r47491: <http://trac.webkit.org/changeset/47491>

[David Kilzer (:ddkilzer)]

All reviewed patches have been landed.  Closing bug.