Closed Bug 1499903 Opened 6 years ago Closed 6 years ago

Correct the events order when we're in the seamless looping

Categories

(Core :: Audio/Video: Playback, enhancement, P3)

enhancement

Tracking

()

RESOLVED FIXED
mozilla65
Tracking Status
firefox65 --- fixed

People

(Reporter: alwu, Assigned: alwu)

References

(Blocks 1 open bug)

Details

Attachments

(4 files, 1 obsolete file)

When the media which has `loop` attribute is playing to the end , the spec mentions that media should do seek to the start position [1]. During seeking, the dispatched events order [2] for MediaElement should be 1. seeking 2. timeupdate 3. seeked However, our current behavior is, 1. timeupdate 2. seeking 3. seeked When MDSM's `mCurrentPosition` changed [3], it would notify MediaDecoder's mirror with DirectTask. However, the way which we use to notify MediaDecoder to dispatch `seeking` and `seek` is a RegularTask [4]. As RegularTask would always be dispatched after DirectTask, we can't dispatch `seeking` before `timeupdate` in our current implementation. [1] https://html.spec.whatwg.org/multipage/media.html#playing-the-media-resource:attr-media-loop-2 [2] https://html.spec.whatwg.org/multipage/media.html#seeking:dom-media-seek [3] https://searchfox.org/mozilla-central/rev/eef79962ba73f7759fd74da658f6e5ceae0fc730/dom/media/MediaDecoderStateMachine.cpp#2973 [4] https://searchfox.org/mozilla-central/rev/eef79962ba73f7759fd74da658f6e5ceae0fc730/dom/media/MediaDecoderStateMachine.cpp#2362
Hi, jya, Here is my preliminary idea, could you give me any suggestion? Thank you.
Attachment #9018102 - Flags: feedback?(jyavenard)
Priority: -- → P2
I'm not sure you need a looping state, and if you could just piggy-back on the decoding state. Or use a new decoding state object that seek back to the first frame when reaching EOS)
Attachment #9018102 - Flags: feedback?(jyavenard)
Priority: P2 → P3
(In reply to Jean-Yves Avenard [:jya] from comment #2) > I'm not sure you need a looping state, and if you could just piggy-back on > the decoding state. Or use a new decoding state object that seek back to the > first frame when reaching EOS) It may be out of topic here, but I like the idea about adding a looping state more. The first attempt to implement seamless looping(bug 654787) is to add the code in decoding state, but it needs to add many specific functions for looping. To keep the logic for decoding as simple as possible, the logic for looping is moved to ReaderProxy. It aims to minimize the complexity for decoding. The benefit for adding a new state is that it won't affect the playback if looping is disabled. It sounds reasonable to me.
(In reply to Chun-Min Chang[:chunmin] from comment #3) > (In reply to Jean-Yves Avenard [:jya] from comment #2) > > I'm not sure you need a looping state, and if you could just piggy-back on > > the decoding state. Or use a new decoding state object that seek back to the > > first frame when reaching EOS) > It may be out of topic here, but I like the idea about adding a looping > state more. The first attempt to implement seamless looping(bug 654787) is > to add the code in decoding state, but it needs to add many specific > functions for looping. To keep the logic for decoding as simple as possible, > the logic for looping is moved to ReaderProxy. It aims to minimize the > complexity for decoding. > > The benefit for adding a new state is that it won't affect the playback if > looping is disabled. It sounds reasonable to me. you don't need to add a new state, you can just inherit a new one from decoding which handle EOS differently... I don't see how that would be much more complex than doing it from the ReaderProxy, quite the opposite
When the media which has `loop` attribute is playing to the end, the spec mentions that media should do seek to the start position [1]. During seeking, the dispatched events order [2] for MediaElement should be 1. seeking 2. timeupdate 3. seeked [1] https://html.spec.whatwg.org/multipage/media.html#playing-the-media-resource:attr-media-loop-2 [2] https://html.spec.whatwg.org/multipage/media.html#seeking:dom-media-seek
Attached file Bug 1499903 - part2 : add test. (deleted) —
Nobody is mirroring to 'mLogicallySeeking', so we can just use boolean instead.
Attachment #9019642 - Attachment description: Bug 1499903 - part3 : change 'mLogicallySeeking' to boolean → Bug 1499903 - part3 : change 'mLogicallySeeking' to Watchable
Pushed by alwu@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/3f6d3c425b42 part1 : correct the events order when we're in the seamless looping. r=chunmin https://hg.mozilla.org/integration/autoland/rev/106752b77131 part2 : add test. r=chunmin https://hg.mozilla.org/integration/autoland/rev/3c7165875616 part3 : change 'mLogicallySeeking' to Watchable r=chunmin
Backed out 3 changesets (Bug 1499903) for causing Bug 1502637 Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=3c7165875616d4b9250815f1a2d324469d5d2a36 Backout link: https://hg.mozilla.org/integration/autoland/rev/c6d1a860e5275fe442ef6319bbc330723e82aa7e Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=208182731&repo=mozilla-central&lineNumber=5689 [task 2018-10-27T12:25:12.765Z] 12:25:12 INFO - GECKO(1711) | [Child 1796, MediaPDecoder #2] WARNING: No previous granule position to use for Opus end trimming.: file /builds/worker/workspace/build/src/dom/media/ogg/OggCodecState.cpp, line 1232 [task 2018-10-27T12:25:12.780Z] 12:25:12 INFO - GECKO(1711) | [Child 1796, MediaPDecoder #2] WARNING: No previous granule position to use for Opus end trimming.: file /builds/worker/workspace/build/src/dom/media/ogg/OggCodecState.cpp, line 1232 [task 2018-10-27T12:25:13.864Z] 12:25:13 INFO - GECKO(1711) | [Child 1796, MediaPDecoder #2] WARNING: No previous granule position to use for Opus end trimming.: file /builds/worker/workspace/build/src/dom/media/ogg/OggCodecState.cpp, line 1232 [task 2018-10-27T12:25:14.074Z] 12:25:14 INFO - GECKO(1711) | [Child 1796, MediaPlayback #4] WARNING: Decoder=7f38e0bd2800 state=SEEKING Audio not synced after seek, maybe a poorly muxed file?: file /builds/worker/workspace/build/src/dom/media/MediaDecoderStateMachine.cpp, line 1213 [task 2018-10-27T12:25:14.448Z] 12:25:14 INFO - GECKO(1711) | [Child 1796, MediaPlayback #2] WARNING: Decoder=7f38e0bd2800 state=SEEKING Audio not synced after seek, maybe a poorly muxed file?: file /builds/worker/workspace/build/src/dom/media/MediaDecoderStateMachine.cpp, line 1213 [task 2018-10-27T12:25:15.272Z] 12:25:15 INFO - GECKO(1711) | --DOCSHELL 0x7f38e1b05800 == 3 [pid = 1796] [id = {f855ddbf-814d-434c-aae1-b5268777a264}] [task 2018-10-27T12:25:18.878Z] 12:25:18 INFO - GECKO(1711) | Assertion failure: ((bool)(__builtin_expect(!!(!NS_FAILED_impl(rv)), 1))), at /builds/worker/workspace/build/src/dom/media/ReaderProxy.cpp:227 [task 2018-10-27T12:26:50.699Z] 12:26:50 INFO - GECKO(1711) | #01: mozilla::ReaderProxy::OnAudioDataRequestFailed(mozilla::MediaResult const&) [dom/media/ReaderProxy.cpp:0] [task 2018-10-27T12:26:50.699Z] 12:26:50 INFO - [task 2018-10-27T12:26:50.699Z] 12:26:50 INFO - GECKO(1711) | #02: mozilla::EnableIf<true, void>::Type mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::InvokeCallbackMethod<true, mozilla::ReaderProxy, RefPtr<mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true> > (mozilla::ReaderProxy::*)(mozilla::MediaResult const&), mozilla::MediaResult, RefPtr<mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::Private> >(mozilla::ReaderProxy*, RefPtr<mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true> > (mozilla::ReaderProxy::*)(mozilla::MediaResult const&), mozilla::MediaResult&&, RefPtr<mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::Private>&&) [mfbt/RefPtr.h:331] [task 2018-10-27T12:26:50.699Z] 12:26:50 INFO - [task 2018-10-27T12:26:50.699Z] 12:26:50 INFO - GECKO(1711) | #03: mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::ThenValue<mozilla::ReaderProxy*, RefPtr<mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true> > (mozilla::ReaderProxy::*)(RefPtr<mozilla::AudioData>), RefPtr<mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true> > (mozilla::ReaderProxy::*)(mozilla::MediaResult const&)>::DoResolveOrRejectInternal(mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::ResolveOrRejectValue&) [mfbt/RefPtr.h:69] [task 2018-10-27T12:26:50.700Z] 12:26:50 INFO - [task 2018-10-27T12:26:50.701Z] 12:26:50 INFO - GECKO(1711) | #04: mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::ThenValueBase::ResolveOrRejectRunnable::Run() [mfbt/RefPtr.h:69] [task 2018-10-27T12:26:50.702Z] 12:26:50 INFO - [task 2018-10-27T12:26:50.702Z] 12:26:50 INFO - GECKO(1711) | #05: mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [mfbt/ThreadLocal.h:177] [task 2018-10-27T12:26:50.703Z] 12:26:50 INFO - [task 2018-10-27T12:26:50.704Z] 12:26:50 INFO - GECKO(1711) | #06: mozilla::TaskQueue::Runner::Run() [xpcom/threads/TaskQueue.cpp:236] [task 2018-10-27T12:26:50.704Z] 12:26:50 INFO - [task 2018-10-27T12:26:50.706Z] 12:26:50 INFO - GECKO(1711) | #07: nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:244]
Flags: needinfo?(alwu)
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Target Milestone: mozilla65 → ---
I don't think the root cause of this intermittent failure is my patch, it seems to me that there is another problem which coincidentally appears. However, we can postpone to land this bug and wait for landing bug 1498440 first which changes ReaderProxy's behaviors a lots and might fix the intermittent failure.
Flags: needinfo?(alwu)
Depends on: 1498440
Pushed by alwu@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/ed4236eceb1a part1 : correct the events order when we're in the seamless looping. r=chunmin
Pushed by alwu@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/634b4c2dad35 part3 : change 'mLogicallySeeking' to Watchable r=chunmin
Backed out 3 changesets (bug 1499903) for frequently asserting at dom/media/MediaDecoderStateMachine.cpp Log: https://treeherder.mozilla.org/logviewer.html#?job_id=210231807&repo=autoland&lineNumber=5163 INFO - TEST-INFO | Main app process: exit 0 [task 2018-11-07T02:58:27.417Z] 02:58:27 INFO - runtests.py | Application ran for: 0:08:53.976891 [task 2018-11-07T02:58:27.417Z] 02:58:27 INFO - zombiecheck | Reading PID log: /tmp/tmpCLPsdEpidlog [task 2018-11-07T02:58:27.418Z] 02:58:27 INFO - ==> process 1752 launched child process 1772 [task 2018-11-07T02:58:27.418Z] 02:58:27 INFO - ==> process 1752 launched child process 1834 [task 2018-11-07T02:58:27.419Z] 02:58:27 INFO - ==> process 1752 launched child process 1859 [task 2018-11-07T02:58:27.419Z] 02:58:27 INFO - ==> process 1752 launched child process 1908 [task 2018-11-07T02:58:27.419Z] 02:58:27 INFO - ==> process 1752 launched child process 3141 [task 2018-11-07T02:58:27.420Z] 02:58:27 INFO - zombiecheck | Checking for orphan process with PID: 1908 [task 2018-11-07T02:58:27.421Z] 02:58:27 INFO - zombiecheck | Checking for orphan process with PID: 1834 [task 2018-11-07T02:58:27.421Z] 02:58:27 INFO - zombiecheck | Checking for orphan process with PID: 1859 [task 2018-11-07T02:58:27.421Z] 02:58:27 INFO - zombiecheck | Checking for orphan process with PID: 1772 [task 2018-11-07T02:58:27.422Z] 02:58:27 INFO - zombiecheck | Checking for orphan process with PID: 3141 [task 2018-11-07T02:58:27.422Z] 02:58:27 INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpdMClOC.mozrunner/minidumps/76ae00ce-9100-07e2-b107-d35eaa2cd45c.dmp /builds/worker/workspace/build/symbols [task 2018-11-07T02:58:38.645Z] 02:58:38 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/76ae00ce-9100-07e2-b107-d35eaa2cd45c.dmp [task 2018-11-07T02:58:38.647Z] 02:58:38 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/76ae00ce-9100-07e2-b107-d35eaa2cd45c.extra [task 2018-11-07T02:58:38.756Z] 02:58:38 INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::MediaDecoderStateMachine::LoopingDecodingState::HandleError(mozilla::MediaResult const&)] [task 2018-11-07T02:58:38.758Z] 02:58:38 INFO - Crash dump filename: /tmp/tmpdMClOC.mozrunner/minidumps/76ae00ce-9100-07e2-b107-d35eaa2cd45c.dmp [task 2018-11-07T02:58:38.758Z] 02:58:38 INFO - Operating system: Linux [task 2018-11-07T02:58:38.759Z] 02:58:38 INFO - 0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64 [task 2018-11-07T02:58:38.759Z] 02:58:38 INFO - CPU: amd64 [task 2018-11-07T02:58:38.760Z] 02:58:38 INFO - family 6 model 62 stepping 4 [task 2018-11-07T02:58:38.761Z] 02:58:38 INFO - 2 CPUs [task 2018-11-07T02:58:38.762Z] 02:58:38 INFO - [task 2018-11-07T02:58:38.762Z] 02:58:38 INFO - GPU: UNKNOWN [task 2018-11-07T02:58:38.763Z] 02:58:38 INFO - [task 2018-11-07T02:58:38.763Z] 02:58:38 INFO - Crash reason: SIGSEGV [task 2018-11-07T02:58:38.764Z] 02:58:38 INFO - Crash address: 0x0 [task 2018-11-07T02:58:38.766Z] 02:58:38 INFO - Process uptime: not available [task 2018-11-07T02:58:38.767Z] 02:58:38 INFO - [task 2018-11-07T02:58:38.767Z] 02:58:38 INFO - Thread 28 (crashed) [task 2018-11-07T02:58:38.768Z] 02:58:38 INFO - 0 libxul.so!mozilla::MediaDecoderStateMachine::LoopingDecodingState::HandleError(mozilla::MediaResult const&) [MediaDecoderStateMachine.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 932 + 0x0] [task 2018-11-07T02:58:38.770Z] 02:58:38 INFO - rax = 0x0000000000000000 rdx = 0x0000000000000000 [task 2018-11-07T02:58:38.771Z] 02:58:38 INFO - rcx = 0x0000000000000000 rbx = 0x00007f2cad73b7c0 [task 2018-11-07T02:58:38.773Z] 02:58:38 INFO - rsi = 0x00007f2ccf4ab770 rdi = 0x00007f2ccf4aa540 [task 2018-11-07T02:58:38.773Z] 02:58:38 INFO - rbp = 0x00007f2cae48c600 rsp = 0x00007f2cae48c5b0 [task 2018-11-07T02:58:38.775Z] 02:58:38 INFO - r8 = 0x00007f2ccf4ab770 r9 = 0x00007f2cae48d700 [task 2018-11-07T02:58:38.776Z] 02:58:38 INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000000 [task 2018-11-07T02:58:38.777Z] 02:58:38 INFO - r12 = 0x00007f2cad73b808 r13 = 0x00007f2cad793200 [task 2018-11-07T02:58:38.778Z] 02:58:38 INFO - r14 = 0x00007f2caa60b1c0 r15 = 0x00007f2cad793200 [task 2018-11-07T02:58:38.778Z] 02:58:38 INFO - rip = 0x00007f2cc02922a9 [task 2018-11-07T02:58:38.779Z] 02:58:38 INFO - Found by: given as instruction pointer in context [task 2018-11-07T02:58:38.781Z] 02:58:38 INFO - 1 libxul.so!mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::ThenValue<mozilla::MediaDecoderStateMachine::LoopingDecodingState::HandleEndOfAudio()::{lambda()#1}::operator()() const::{lambda(RefPtr<mozilla::AudioData>)#1}, mozilla::MediaDecoderStateMachine::LoopingDecodingState::HandleEndOfAudio()::{lambda()#1}::operator()() const::{lambda(mozilla::MediaResult const&)#1}>::DoResolveOrRejectInternal(mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::ResolveOrRejectValue&) [MediaDecoderStateMachine.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 917 + 0xb] [task 2018-11-07T02:58:38.782Z] 02:58:38 INFO - rbx = 0x00007f2cad73b7c0 rbp = 0x00007f2cae48c630 [task 2018-11-07T02:58:38.783Z] 02:58:38 INFO - rsp = 0x00007f2cae48c610 r12 = 0x00007f2cad73b808 [task 2018-11-07T02:58:38.783Z] 02:58:38 INFO - r13 = 0x0000000000000000 r14 = 0x00007f2caa60b1c0 [task 2018-11-07T02:58:38.784Z] 02:58:38 INFO - r15 = 0x00007f2cad793200 rip = 0x00007f2cc0291ce4 [task 2018-11-07T02:58:38.785Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.786Z] 02:58:38 INFO - 2 libxul.so!mozilla::MozPromise<RefPtr<mozilla::AudioData>, mozilla::MediaResult, true>::ThenValueBase::ResolveOrRejectRunnable::Run() [MozPromise.h:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 411 + 0xb] [task 2018-11-07T02:58:38.788Z] 02:58:38 INFO - rbx = 0x00007f2ca95fc578 rbp = 0x00007f2cae48c660 [task 2018-11-07T02:58:38.788Z] 02:58:38 INFO - rsp = 0x00007f2cae48c640 r12 = 0x0000000000000008 [task 2018-11-07T02:58:38.789Z] 02:58:38 INFO - r13 = 0x0000000000000000 r14 = 0x00007f2ca95fc540 [task 2018-11-07T02:58:38.791Z] 02:58:38 INFO - r15 = 0x00007f2cad73b7c0 rip = 0x00007f2cc0292877 [task 2018-11-07T02:58:38.791Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.792Z] 02:58:38 INFO - 3 libxul.so!mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [TaskDispatcher.h:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 214 + 0x9] [task 2018-11-07T02:58:38.792Z] 02:58:38 INFO - rbx = 0x0000000000000000 rbp = 0x00007f2cae48c690 [task 2018-11-07T02:58:38.793Z] 02:58:38 INFO - rsp = 0x00007f2cae48c670 r12 = 0x0000000000000008 [task 2018-11-07T02:58:38.793Z] 02:58:38 INFO - r13 = 0x0000000000000000 r14 = 0x00007f2cb56a2000 [task 2018-11-07T02:58:38.793Z] 02:58:38 INFO - r15 = 0x00007f2cad714518 rip = 0x00007f2cbe6f64a4 [task 2018-11-07T02:58:38.794Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.794Z] 02:58:38 INFO - 4 libxul.so!mozilla::TaskQueue::Runner::Run() [TaskQueue.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 235 + 0x9] [task 2018-11-07T02:58:38.794Z] 02:58:38 INFO - rbx = 0x00007f2cae48c730 rbp = 0x00007f2cae48c760 [task 2018-11-07T02:58:38.794Z] 02:58:38 INFO - rsp = 0x00007f2cae48c6a0 r12 = 0x00007f2cad73c188 [task 2018-11-07T02:58:38.796Z] 02:58:38 INFO - r13 = 0x0000000000000000 r14 = 0x00007f2cad7144f0 [task 2018-11-07T02:58:38.796Z] 02:58:38 INFO - r15 = 0x00007f2cae48c6a8 rip = 0x00007f2cbe6fb194 [task 2018-11-07T02:58:38.796Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.796Z] 02:58:38 INFO - 5 libxul.so!nsThreadPool::Run() [nsThreadPool.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 245 + 0x9] [task 2018-11-07T02:58:38.797Z] 02:58:38 INFO - rbx = 0x00007f2cae48c7d8 rbp = 0x00007f2cae48c830 [task 2018-11-07T02:58:38.797Z] 02:58:38 INFO - rsp = 0x00007f2cae48c770 r12 = 0x00007f2cae48c7c0 [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - r13 = 0x00007f2cb58b43a8 r14 = 0x00007f2cb58b4310 [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - r15 = 0x00007f2cae48c7e8 rip = 0x00007f2cbe7090d8 [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - 6 libxul.so!non-virtual thunk to nsThreadPool::Run() [nsThreadPool.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 0 + 0x5] [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - rbx = 0x00007f2cb58b42f0 rbp = 0x00007f2cae48c840 [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - rsp = 0x00007f2cae48c840 r12 = 0x00007f2cb569a860 [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - r13 = 0x0000000000000001 r14 = 0x00007f2cb569a7c0 [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - r15 = 0x00000000ffffffff rip = 0x00007f2cbe7091c7 [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - 7 libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 1246 + 0x9] [task 2018-11-07T02:58:38.798Z] 02:58:38 INFO - rbx = 0x00007f2cb58b42f0 rbp = 0x00007f2cae48cda0 [task 2018-11-07T02:58:38.799Z] 02:58:38 INFO - rsp = 0x00007f2cae48c850 r12 = 0x00007f2cb569a860 [task 2018-11-07T02:58:38.799Z] 02:58:38 INFO - r13 = 0x0000000000000001 r14 = 0x00007f2cb569a7c0 [task 2018-11-07T02:58:38.799Z] 02:58:38 INFO - r15 = 0x00000000ffffffff rip = 0x00007f2cbe705553 [task 2018-11-07T02:58:38.799Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.799Z] 02:58:38 INFO - 8 libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 530 + 0x10] [task 2018-11-07T02:58:38.799Z] 02:58:38 INFO - rbx = 0x0000000000000001 rbp = 0x00007f2cae48cdd0 [task 2018-11-07T02:58:38.799Z] 02:58:38 INFO - rsp = 0x00007f2cae48cdb0 r12 = 0x0000000000000000 [task 2018-11-07T02:58:38.799Z] 02:58:38 INFO - r13 = 0x00007f2cad8390a0 r14 = 0x00007f2cae48cdbf [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - r15 = 0x00007f2cb569a7c0 rip = 0x00007f2cbe7078a7 [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - 9 libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 364 + 0xd] [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - rbx = 0x00007f2cb56c2ae0 rbp = 0x00007f2cae48ce20 [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - rsp = 0x00007f2cae48cde0 r12 = 0x0000000000000000 [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - r13 = 0x00007f2cad8390a0 r14 = 0x00007f2cad839080 [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - r15 = 0x00007f2cb569a7c0 rip = 0x00007f2cbeb8bb90 [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - 10 libxul.so!MessageLoop::Run() [message_loop.cc:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 318 + 0x8] [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - rbx = 0x00007f2cb56c2ae0 rbp = 0x00007f2cae48ce60 [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - rsp = 0x00007f2cae48ce30 r12 = 0x00007f2cae48ce90 [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - r13 = 0x00007f2cb569a7c0 r14 = 0x00007f2cae48ce38 [task 2018-11-07T02:58:38.800Z] 02:58:38 INFO - r15 = 0x00007f2cb56c2ae0 rip = 0x00007f2cbeb56a5f [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - 11 libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 505 + 0x8] [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - rbx = 0x00007f2cc54878f8 rbp = 0x00007f2cae48cec0 [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - rsp = 0x00007f2cae48ce70 r12 = 0x00007f2cae48ce90 [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - r13 = 0x00007f2cb569a7c0 r14 = 0x00007f2cb569a800 [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - r15 = 0x00007f2cb56c2ae0 rip = 0x00007f2cbe7033f3 [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - 12 libnspr4.so!_pt_root [ptthread.c:a15aa42f102ea8c042eff3d5e8e2b08f22f01663 : 201 + 0x3] [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - rbx = 0x00007f2caca865e0 rbp = 0x00007f2cae48cf10 [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - rsp = 0x00007f2cae48ced0 r12 = 0x00007f2cae48d670 [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000c3e [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - r15 = 0x00007f2cae48d700 rip = 0x00007f2cd0547d6e [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - 13 libpthread-2.23.so + 0x76ba [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - rbx = 0x0000000000000000 rbp = 0x0000000000000000 [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - rsp = 0x00007f2cae48cf20 r12 = 0x0000000000000000 [task 2018-11-07T02:58:38.801Z] 02:58:38 INFO - r13 = 0x00007ffcb30ef1bf r14 = 0x0000000000040000 [task 2018-11-07T02:58:38.802Z] 02:58:38 INFO - r15 = 0x00007f2cb5b98930 rip = 0x00007f2cd01636ba [task 2018-11-07T02:58:38.802Z] 02:58:38 INFO - Found by: call frame info [task 2018-11-07T02:58:38.802Z] 02:58:38 INFO - 14 libc-2.23.so + 0x10741d [task 2018-11-07T02:58:38.802Z] 02:58:38 INFO - rsp = 0x00007f2cae48cfc0 rip = 0x00007f2ccf1ec41d [task 2018-11-07T02:58:38.802Z] 02:58:38 INFO - Found by: stack scanning Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&revision=ed4236eceb1a4cae6b50523b019934bda58dcd8b Backout: https://hg.mozilla.org/integration/autoland/rev/88469512befe15042bbdbd6d7d6eb012c20900ee
Flags: needinfo?(alwu)
Hi, Jya, Comment16 pointed out that sometime we would hit the assertion when running `test_looping_eventsOrder.html` on Linux, and I can't reproduce it on desktop. I have no idea why we would get EOS after seeking to the head position, the only situation I can image is that the audio track only contains audio sample with negative start time. However, it's apparently not a case I assumed because I checked all files in `gSmallTests`, none of them are this kind of file. Do you have any idea? If not, I would like to remove the assertion first as a solution. Thank you.
Flags: needinfo?(alwu) → needinfo?(jyavenard)
Problem resolved. This can now reland.
Flags: needinfo?(jyavenard)
The failure still exists, there are 3 fails from 50 times on try. I still have no idea about this failure, so I'm going to remove the assertion as temporary solution. [1] https://treeherder.mozilla.org/#/jobs?repo=try&revision=4599edbdde02bea581c4cc4b8338e7a96befcc4a
Attached file Bug 1499903 - part4 : remove assertion. (obsolete) (deleted) —
Now the problem is that we would hit a assertion which is that we can't get data after seeking to 0s when we use `gSmallTests` in `test_looping_eventsOrder.html`. That assertion is not easy to find the root cause, I can only reproduce it on try server. In order not to block following implementation of seamless looping, I decide not to use `gSmallTests` in `test_looping_eventsOrder.html.`, and choose the video and audio which will not hit the assertion, and then land this bug first. I tried to push only test part on try server without patch1 and patch2, and I still got the assertion fail which means the assertion is not part of this bug, I will continue investigating it on bug1508501.
Attachment #9025821 - Attachment is obsolete: true
Pushed by alwu@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/55b9e352f46d part1 : correct the events order when we're in the seamless looping. r=chunmin https://hg.mozilla.org/integration/autoland/rev/7b73044f0618 part2 : add test. r=chunmin https://hg.mozilla.org/integration/autoland/rev/0f223b4c9a71 part3 : change 'mLogicallySeeking' to Watchable r=chunmin
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla65
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: