Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

StreamingEngine test failures on Tizen #4806

Closed
joeyparrish opened this issue Dec 9, 2022 · 2 comments · Fixed by #4812
Closed

StreamingEngine test failures on Tizen #4806

joeyparrish opened this issue Dec 9, 2022 · 2 comments · Fixed by #4812
Assignees
Labels
component: tests The issue involves our automated tests (generally; otherwise use a more specific component) priority: P2 Smaller impact or easy workaround status: archived Archived and locked; will not be updated type: code health A code health issue
Milestone

Comments

@joeyparrish
Copy link
Member

These tests have been failing on Tizen since we re-enabled that platform in the lab 23 days ago:

1) plays through Period transition
     StreamingEngine Live
     Error: Timeout waiting for movement from 0 to 305
current time: 300.15
duration: 4294967296
ready state: 2
playback rate: 1
paused: false
ended: false
buffered: {"total":[{"start":291.019,"end":300},{"start":300.15,"end":339.999}],"audio":[{"start":291.019,"end":300},{"start":300.15,"end":340.17}],"video":[{"start":290,"end":339.999}],"text":[]}

Error: Timeout waiting for movement from 0 to 305
current time: 300.15
duration: 4294967296
ready state: 2
playback rate: 1
paused: false
ended: false
buffered: {"total":[{"start":291.019,"end":300},{"start":300.15,"end":339.999}],"audio":[{"start":291.019,"end":300},{"start":300.15,"end":340.17}],"video":[{"start":290,"end":339.999}],"text":[]}
    at _class.waitUntilGeneric_ (test/test/util/waiter.js:279:19 <- test/test/util/waiter.js:322:19)
    at _class.waitUntilPlayheadReaches (test/test/util/waiter.js:131:17 <- test/test/util/waiter.js:155:19)
    at _callee8$ (test/media/streaming_engine_integration.js:357:37 <- test/media/streaming_engine_integration.js:511:46)
    at tryCatch (node_modules/@babel/polyfill/dist/polyfill.js:6473:40)
    at GeneratorFunctionPrototype.invoke [as _invoke] (node_modules/@babel/polyfill/dist/polyfill.js:6702:22)
    at GeneratorFunctionPrototype.prototype.(anonymous function) [as next] (node_modules/@babel/polyfill/dist/polyfill.js:6525:21)
    at asyncGeneratorStep (test/ui/ui_integration.js:31:103)
    at _next (test/media/streaming_engine_integration.js:5:194)
    at run (node_modules/@babel/polyfill/dist/polyfill.js:4536:22)
    at node_modules/@babel/polyfill/dist/polyfill.js:4553:30

2) can handle seeks ahead of availability window
     StreamingEngine Live
     Error: Timeout waiting for movement from 285.675 to 305
current time: 300.15
duration: 4294967296
ready state: 2
playback rate: 1
paused: false
ended: false
buffered: {"total":[{"start":291.019,"end":300},{"start":300.15,"end":339.999}],"audio":[{"start":291.019,"end":300},{"start":300.15,"end":340.17}],"video":[{"start":290,"end":339.999}],"text":[]}

Error: Timeout waiting for movement from 285.675 to 305
current time: 300.15
duration: 4294967296
ready state: 2
playback rate: 1
paused: false
ended: false
buffered: {"total":[{"start":291.019,"end":300},{"start":300.15,"end":339.999}],"audio":[{"start":291.019,"end":300},{"start":300.15,"end":340.17}],"video":[{"start":290,"end":339.999}],"text":[]}
    at _class.waitUntilGeneric_ (test/test/util/waiter.js:279:19 <- test/test/util/waiter.js:322:19)
    at _class.waitUntilPlayheadReaches (test/test/util/waiter.js:131:17 <- test/test/util/waiter.js:155:19)
    at _callee9$ (test/media/streaming_engine_integration.js:381:37 <- test/media/streaming_engine_integration.js:555:46)
    at tryCatch (node_modules/@babel/polyfill/dist/polyfill.js:6473:40)
    at GeneratorFunctionPrototype.invoke [as _invoke] (node_modules/@babel/polyfill/dist/polyfill.js:6702:22)
    at GeneratorFunctionPrototype.prototype.(anonymous function) [as next] (node_modules/@babel/polyfill/dist/polyfill.js:6525:21)
    at asyncGeneratorStep (test/ui/ui_integration.js:31:103)
    at _next (test/media/streaming_engine_integration.js:5:194)
    at run (node_modules/@babel/polyfill/dist/polyfill.js:4536:22)
    at node_modules/@babel/polyfill/dist/polyfill.js:4553:30

3) can handle seeks behind availability window
     StreamingEngine Live
     Error: Timeout waiting for movement from [145](https://github.com/shaka-project/shaka-player/actions/runs/3647347351/jobs/6160460024#step:9:146) to 305
current time: 300.15
duration: 4294967296
ready state: 3
playback rate: 1
paused: false
ended: false
buffered: {"total":[{"start":291.019,"end":300},{"start":300.15,"end":339.999}],"audio":[{"start":291.019,"end":300},{"start":300.15,"end":340.17}],"video":[{"start":290,"end":339.999}],"text":[]}

Error: Timeout waiting for movement from 145 to 305
current time: 300.15
duration: 4294967296
ready state: 3
playback rate: 1
paused: false
ended: false
buffered: {"total":[{"start":291.019,"end":300},{"start":300.15,"end":339.999}],"audio":[{"start":291.019,"end":300},{"start":300.15,"end":340.17}],"video":[{"start":290,"end":339.999}],"text":[]}
    at _class.waitUntilGeneric_ (test/test/util/waiter.js:279:19 <- test/test/util/waiter.js:322:19)
    at _class.waitUntilPlayheadReaches (test/test/util/waiter.js:131:17 <- test/test/util/waiter.js:[155](https://github.com/shaka-project/shaka-player/actions/runs/3647347351/jobs/6160460024#step:9:156):19)
    at _callee10$ (test/media/streaming_engine_integration.js:402:37 <- test/media/streaming_engine_integration.js:590:46)
    at tryCatch (node_modules/@babel/polyfill/dist/polyfill.js:6473:40)
    at GeneratorFunctionPrototype.invoke [as _invoke] (node_modules/@babel/polyfill/dist/polyfill.js:6702:22)
    at GeneratorFunctionPrototype.prototype.(anonymous function) [as next] (node_modules/@babel/polyfill/dist/polyfill.js:6525:21)
    at asyncGeneratorStep (test/ui/ui_integration.js:31:103)
    at _next (test/media/streaming_engine_integration.js:5:194)
    at run (node_modules/@babel/polyfill/dist/polyfill.js:4536:22)
    at node_modules/@babel/polyfill/dist/polyfill.js:4553:30

Lab runs in general have been so flaky that I overlooked this until now. But this is consistent, and all 4 maintained branches are behaving this way with the same tests. (v3.2, v3.3, v4.2, v4.3)

@joeyparrish joeyparrish added type: code health A code health issue priority: P2 Smaller impact or easy workaround component: tests The issue involves our automated tests (generally; otherwise use a more specific component) labels Dec 9, 2022
@joeyparrish joeyparrish self-assigned this Dec 9, 2022
@github-actions github-actions bot added this to the Backlog milestone Dec 9, 2022
@joeyparrish
Copy link
Member Author

I see that there is a 150 ms gap in audio, and that gap jumping is ineffective for some reason.

I was trying to figure out why there would be a 150ms gap, and I'm not sure at all. Each "frame" of audio is 1024 samples at 48kHZ, and the segment has 469 frames containing a total of 480256 samples for a duration of 10.005333... seconds. The metadata in our tests lists the audio segment's length at 10.005 seconds even. The video segment is exactly 10 seconds long.

Based on the above data, I tried three ways to address this in the tests:

  1. Change metadata for our fake audio segment from 10.005 to 10 (to align with video, overlap ~5ms of audio on each append) - not sure why cutting off 5.3333ms is better than cutting 0.3333ms, but it removes the gap entirely.
  2. Change metadata for our fake audio segment from 10.005 to 10.00534 (near to actual value of 10.0053333....) - this doesn't get rid of the gap, but makes the gap is 10ms longer (160ms), and then we somehow manage to jump it correctly.
  3. Change gap jumping to jump to a later position - rather than get rid of a weird gap, make jumping somewhat more robust against rounding errors.

I think a solution that makes playback more robust both inside and outside of tests would probably be the best option, since gaps can and do happen in real life and the player is meant to survive them.

But jumping 1ms farther didn't work. In fact, video.currentTime after the jump was still 300.150, even though it should have been 300.151. Jumping 2ms farther also had no effect. Jumping 5ms farther got us to 300.155 as it should, but playback was still stuck at that point.

If there is some way to fix this at the level of gap-jumping, I'll do that. Otherwise, I'll fall back to removing the gap from the tests.

@joeyparrish
Copy link
Member Author

In all cases, when playback is stuck, readyState is "2", which doesn't seem right given the buffered ranges.

The gap-jumping change doesn't seem to be viable:

jump ahead status
1ms no effect
2ms no effect
5ms seeks correctly, still stuck
100ms seeks correctly, still stuck
1s seeks correctly, still stuck
4s seeks correctly, still stuck
8s works 😭

If we have to seek that far ahead of the gap to make this scenario work on Tizen, I don't think we'll be able to do that in production.

joeyparrish added a commit to joeyparrish/shaka-player that referenced this issue Dec 9, 2022
For some unknown reason, using precise durations for these audio
segments on Tizen creates gaps that can't be survived.  I don't know
why that creates a 150ms gap, and I don't know why we can't seem to
jump over it.  It feels very much like a bug in Tizen itself.

Experimentally, I found that rounding these durations to 10s even
removes the gap completely.  I tried many other things, but this is
the only reasonable thing I have found that works.

More details on my investigations can be found in the issue on GitHub.

Closes shaka-project#4806
joeyparrish added a commit that referenced this issue Dec 14, 2022
For some unknown reason, using precise durations for these audio
segments on Tizen creates gaps that can't be survived. I don't know why
that creates a 150ms gap, and I don't know why we can't seem to jump
over it. It feels very much like a bug in Tizen itself.

Experimentally, I found that rounding these durations to 10s even
removes the gap completely. I tried many other things, but this is the
only reasonable thing I have found that works.

More details on my investigations can be found in the issue on GitHub.

This change in durations exposed some brittle tests in Player which had
to be adjusted to be more robust.

Closes #4806
joeyparrish added a commit that referenced this issue Dec 14, 2022
For some unknown reason, using precise durations for these audio
segments on Tizen creates gaps that can't be survived. I don't know why
that creates a 150ms gap, and I don't know why we can't seem to jump
over it. It feels very much like a bug in Tizen itself.

Experimentally, I found that rounding these durations to 10s even
removes the gap completely. I tried many other things, but this is the
only reasonable thing I have found that works.

More details on my investigations can be found in the issue on GitHub.

This change in durations exposed some brittle tests in Player which had
to be adjusted to be more robust.

Closes #4806
joeyparrish added a commit that referenced this issue Dec 14, 2022
For some unknown reason, using precise durations for these audio
segments on Tizen creates gaps that can't be survived. I don't know why
that creates a 150ms gap, and I don't know why we can't seem to jump
over it. It feels very much like a bug in Tizen itself.

Experimentally, I found that rounding these durations to 10s even
removes the gap completely. I tried many other things, but this is the
only reasonable thing I have found that works.

More details on my investigations can be found in the issue on GitHub.

This change in durations exposed some brittle tests in Player which had
to be adjusted to be more robust.

Closes #4806
joeyparrish added a commit that referenced this issue Dec 14, 2022
For some unknown reason, using precise durations for these audio
segments on Tizen creates gaps that can't be survived. I don't know why
that creates a 150ms gap, and I don't know why we can't seem to jump
over it. It feels very much like a bug in Tizen itself.

Experimentally, I found that rounding these durations to 10s even
removes the gap completely. I tried many other things, but this is the
only reasonable thing I have found that works.

More details on my investigations can be found in the issue on GitHub.

This change in durations exposed some brittle tests in Player which had
to be adjusted to be more robust.

Closes #4806
@avelad avelad modified the milestones: Backlog, v4.4 Feb 3, 2023
Robloche pushed a commit to Robloche/shaka-player that referenced this issue Feb 8, 2023
For some unknown reason, using precise durations for these audio
segments on Tizen creates gaps that can't be survived. I don't know why
that creates a 150ms gap, and I don't know why we can't seem to jump
over it. It feels very much like a bug in Tizen itself.

Experimentally, I found that rounding these durations to 10s even
removes the gap completely. I tried many other things, but this is the
only reasonable thing I have found that works.

More details on my investigations can be found in the issue on GitHub.

This change in durations exposed some brittle tests in Player which had
to be adjusted to be more robust.

Closes shaka-project#4806
@github-actions github-actions bot added the status: archived Archived and locked; will not be updated label Feb 11, 2023
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Feb 11, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
component: tests The issue involves our automated tests (generally; otherwise use a more specific component) priority: P2 Smaller impact or easy workaround status: archived Archived and locked; will not be updated type: code health A code health issue
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants