Bug 72279 - media/track/track-webvtt-tc004-magic-header.html flakily times out
Summary: media/track/track-webvtt-tc004-magic-header.html flakily times out
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: WebCore Misc. (show other bugs)
Version: 528+ (Nightly build)
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Anna Cavender
URL:
Keywords: InRadar
Depends on:
Blocks: 43668 82590
  Show dependency treegraph
 
Reported: 2011-11-14 08:50 PST by Tony Gentilcore
Modified: 2012-04-05 11:32 PDT (History)
7 users (show)

See Also:


Attachments
Patch (1.29 KB, patch)
2011-11-14 08:52 PST, Tony Gentilcore
no flags Details | Formatted Diff | Diff
Patch (7.36 KB, patch)
2012-03-29 01:23 PDT, Zan Dobersek
no flags Details | Formatted Diff | Diff
Patch (9.96 KB, patch)
2012-03-30 01:52 PDT, Zan Dobersek
no flags Details | Formatted Diff | Diff
Patch (12.25 KB, patch)
2012-04-05 07:17 PDT, Zan Dobersek
no flags Details | Formatted Diff | Diff
Updated reviewed patch (12.08 KB, patch)
2012-04-05 10:04 PDT, Zan Dobersek
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Tony Gentilcore 2011-11-14 08:50:27 PST
media/track/track-webvtt-tc004-magic-header.html has been flakily timing out since r100085.

Flakiness dashboard:
http://test-results.appspot.com/dashboards/flakiness_dashboard.html#tests=media%2Ftrack%2Ftrack-webvtt-tc004-magic-header.html

I'm updating the expectations now.
Comment 1 Tony Gentilcore 2011-11-14 08:52:30 PST
Created attachment 114957 [details]
Patch
Comment 2 Tony Gentilcore 2011-11-14 08:53:07 PST
Committed r100149: <http://trac.webkit.org/changeset/100149>
Comment 3 Vsevolod Vlasov 2011-12-02 03:20:26 PST
This test is failing all the time on win and not so often on linux.

Added TEXT to expectations.
http://trac.webkit.org/changeset/101776
Comment 4 Zan Dobersek 2012-03-29 01:21:38 PDT
The problem occurs when parsing the third, erroneous track is being parsed. Currently a parser is automatically created if the response in TextTrackLoader::processNewCueData has text/vtt as mime type. This also happens with the mentioned track, causing the start of parsing. The parsing does not get over the Initial state in WebVTTParser::parseBytes, as the identifier could not be found, but the parser doesn't register this as an error and doesn't notify the client.

Patch incoming.
Comment 5 Zan Dobersek 2012-03-29 01:23:02 PDT
Created attachment 134522 [details]
Patch
Comment 6 Zan Dobersek 2012-03-29 03:11:10 PDT
Comment on attachment 134522 [details]
Patch

Also setting the cq flag.
Comment 7 Eric Carlson 2012-03-29 09:29:27 PDT
Comment on attachment 134522 [details]
Patch

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

This is close, but I would prefer to have the cleanup noted. Thanks for identifying the issue and taking it on!

> Source/WebCore/html/track/WebVTTParser.cpp:141
>          case Initial:
>              // 4-12 - Collect the first line and check for "WEBVTT".
> -            if (!hasRequiredFileIdentifier(data, length))
> +            if (!hasRequiredFileIdentifier(data, length)) {
> +                if (m_client)
> +                    m_client->fileUnsuccessfullyParsed();
>                  return;
> +            }

"fileUnsuccessfullyParsed" is awkward, how about something like "fileFailedToParse", or "invalidFile" instead?

As long as you are fixing this, I think it would be a good idea to move *all* of the logic about the file identifier into the parser. IOW, allow the client to call parseBytes() immediately instead of waiting until it knows that there is enough data loaded to check the file identifier. This will require the parser stay in the "Initial" state until can check for the identifier, but that will only require us to buffer up to 6 or 9 bytes before checking for the identifier.

> Source/WebCore/loader/TextTrackLoader.cpp:195
> +

Please include the error LOG(...) here.
Comment 8 Zan Dobersek 2012-03-29 11:45:41 PDT
Comment on attachment 134522 [details]
Patch

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

>> Source/WebCore/html/track/WebVTTParser.cpp:141
>> +            }
> 
> "fileUnsuccessfullyParsed" is awkward, how about something like "fileFailedToParse", or "invalidFile" instead?
> 
> As long as you are fixing this, I think it would be a good idea to move *all* of the logic about the file identifier into the parser. IOW, allow the client to call parseBytes() immediately instead of waiting until it knows that there is enough data loaded to check the file identifier. This will require the parser stay in the "Initial" state until can check for the identifier, but that will only require us to buffer up to 6 or 9 bytes before checking for the identifier.

Should I then make WebVTTParser operate directly on the SharedBuffer that's provided by CachedResource in TextTrackLoader::processNewCueData? Progressing this idea, would it be safe to pass over the pointer to SharedBuffer already when constructing the parser? Current parsing offset would the move to be stored in the parser, making TextTrackLoader pretty much free of parser-related bloat.

Noted and agreed on the name.

>> Source/WebCore/loader/TextTrackLoader.cpp:195
>> +
> 
> Please include the error LOG(...) here.

Through a quick look I only found LOG macros used in track-related files on two occasions. I agree logging should be done, not only here though but rather throughout track-related operations. Because of that I recommend populating the code with logging info for another patch. I can commit to creating a bug, CC-ing people and creating the patch in near-future.
Comment 9 Eric Carlson 2012-03-29 15:05:08 PDT
(In reply to comment #8)
> (From update of attachment 134522 [details])
> View in context: https://bugs.webkit.org/attachment.cgi?id=134522&action=review
> 
> >> Source/WebCore/html/track/WebVTTParser.cpp:141
> >> +            }
> > 
> > "fileUnsuccessfullyParsed" is awkward, how about something like "fileFailedToParse", or "invalidFile" instead?
> > 
> > As long as you are fixing this, I think it would be a good idea to move *all* of the logic about the file identifier into the parser. IOW, allow the client to call parseBytes() immediately instead of waiting until it knows that there is enough data loaded to check the file identifier. This will require the parser stay in the "Initial" state until can check for the identifier, but that will only require us to buffer up to 6 or 9 bytes before checking for the identifier.
> 
> Should I then make WebVTTParser operate directly on the SharedBuffer that's provided by CachedResource in TextTrackLoader::processNewCueData? Progressing this idea, would it be safe to pass over the pointer to SharedBuffer already when constructing the parser? Current parsing offset would the move to be stored in the parser, making TextTrackLoader pretty much free of parser-related bloat.
> 

It already does operate on it in as much as it is passed a pointer to the data contained in the shared buffer. I do not think it make sense to change the API to always take a SharedBuffer instead of a const char *. This is not how any of the other WebKit parsers work, and it make the lifetime management of the buffer much more complicated.

> 
> >> Source/WebCore/loader/TextTrackLoader.cpp:195
> >> +
> > 
> > Please include the error LOG(...) here.
> 
> Through a quick look I only found LOG macros used in track-related files on two occasions. I agree logging should be done, not only here though but rather throughout track-related operations. Because of that I recommend populating the code with logging info for another patch. I can commit to creating a bug, CC-ing people and creating the patch in near-future.

I definitely agree that we should have more consistent logging in other track related functions, but I don't think this is a reason to remove the error logging here.
Comment 10 Zan Dobersek 2012-03-30 01:50:14 PDT
(In reply to comment #9)
> (In reply to comment #8)
> > (From update of attachment 134522 [details] [details])
> > View in context: https://bugs.webkit.org/attachment.cgi?id=134522&action=review
> > 
> > >> Source/WebCore/html/track/WebVTTParser.cpp:141
> > >> +            }
> > > 
> > > "fileUnsuccessfullyParsed" is awkward, how about something like "fileFailedToParse", or "invalidFile" instead?
> > > 
> > > As long as you are fixing this, I think it would be a good idea to move *all* of the logic about the file identifier into the parser. IOW, allow the client to call parseBytes() immediately instead of waiting until it knows that there is enough data loaded to check the file identifier. This will require the parser stay in the "Initial" state until can check for the identifier, but that will only require us to buffer up to 6 or 9 bytes before checking for the identifier.
> > 
> > Should I then make WebVTTParser operate directly on the SharedBuffer that's provided by CachedResource in TextTrackLoader::processNewCueData? Progressing this idea, would it be safe to pass over the pointer to SharedBuffer already when constructing the parser? Current parsing offset would the move to be stored in the parser, making TextTrackLoader pretty much free of parser-related bloat.
> > 
> 
> It already does operate on it in as much as it is passed a pointer to the data contained in the shared buffer. I do not think it make sense to change the API to always take a SharedBuffer instead of a const char *. This is not how any of the other WebKit parsers work, and it make the lifetime management of the buffer much more complicated.
> 

Ok, noted.

> > 
> > >> Source/WebCore/loader/TextTrackLoader.cpp:195
> > >> +
> > > 
> > > Please include the error LOG(...) here.
> > 
> > Through a quick look I only found LOG macros used in track-related files on two occasions. I agree logging should be done, not only here though but rather throughout track-related operations. Because of that I recommend populating the code with logging info for another patch. I can commit to creating a bug, CC-ing people and creating the patch in near-future.
> 
> I definitely agree that we should have more consistent logging in other track related functions, but I don't think this is a reason to remove the error logging here.

Right then, might as well start logging here.
Comment 11 Zan Dobersek 2012-03-30 01:52:51 PDT
Created attachment 134747 [details]
Patch

Also fixes a typo throughout WebVTTParser.
Comment 12 Eric Carlson 2012-03-30 07:07:23 PDT
Comment on attachment 134747 [details]
Patch

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

> Source/WebCore/html/track/WebVTTParser.cpp:133
> +            if (length < bomLength + fileIdentifierLength)
> +                return;

The parser only sees each byte once, so won't we now report failure if the first call to parseBytes() passes less than 9 bytes? I think you need to accumulate the first 9 bytes into a member variable and test that.
Comment 13 Zan Dobersek 2012-04-05 07:17:18 PDT
Created attachment 135819 [details]
Patch

Store identifier data until there's enough of it.
Comment 14 Eric Carlson 2012-04-05 08:11:31 PDT
Comment on attachment 135819 [details]
Patch

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

Nice fix, thanks! Marking r+ but cq- because of the extraneous fprintf().

> Source/WebCore/html/track/WebVTTParser.cpp:152
> +    if (m_identifierData.size() >= bomLength && m_identifierData[0] == '\xEF'
> +        && m_identifierData[1] == '\xBB' && m_identifierData[2] == '\xBF')
> +        position += bomLength;

Nit: I don't think breaking the "if" line helps readability as it makes it harder to see which line is executed when the condition is true.

> Source/WebCore/html/track/WebVTTParser.cpp:154
> +    fprintf(stderr, "WebVTTParser::hasRequiredFileIdentifier\n%s\n", line.utf8().data());

Oops, looks like you forgot to remove some debugging code.
Comment 15 Zan Dobersek 2012-04-05 10:04:03 PDT
Created attachment 135845 [details]
Updated reviewed patch

Thanks for the reviews! Still asking for a cq+ though, thanks in advance.
Comment 16 Radar WebKit Bug Importer 2012-04-05 10:53:06 PDT
<rdar://problem/11192490>
Comment 17 WebKit Review Bot 2012-04-05 11:32:38 PDT
Comment on attachment 135845 [details]
Updated reviewed patch

Clearing flags on attachment: 135845

Committed r113343: <http://trac.webkit.org/changeset/113343>
Comment 18 WebKit Review Bot 2012-04-05 11:32:44 PDT
All reviewed patches have been landed.  Closing bug.