Closed Bug 1008057 Opened 10 years ago Closed 10 years ago

Assertion failure: mCurrentFrameTime <= clock_time || mPlaybackRate <= 0 (Clock should go forwards if the playback rate is > 0.), at ../../../gecko/content/media/MediaDecoderStateMachine.cpp:2417

Categories

(Core :: Audio/Video, defect)

Product:
Core
Component:
Audio/Video
Platform:
ARM
Gonk (Firefox OS)
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla32

People

(Reporter: jwwang, Assigned: jwwang)

References

Details

Attachments

(1 file, 2 obsolete files)

1008057_fix_AudioStreamClock-v3.patch
6.96 KB, patch
jwwang
: review+
Details | Diff | Splinter Review 
https://tbpl.mozilla.org/php/getParsedLog.php?id=39326030&tree=Try&full=1#error5
file: https://hg.mozilla.org/try/file/215f78e95c6d/content/media/MediaDecoderStateMachine.cpp#l2417

call stack:
19:18:58  WARNING -  PROCESS-CRASH | /tests/content/media/test/test_clone_media_element.html | application crashed [@ mozilla::MediaDecoderStateMachine::GetClock()]
19:18:58     INFO -  Crash dump filename: /tmp/tmpNFyuOp/687391c2-69ae-7f2e-2290a3e0-1b72e88c.dmp
19:18:58     INFO -  Operating system: Android
19:18:58     INFO -                    0.0.0 Linux 2.6.29-00302-g586075d #31 Mon Feb 24 10:28:23 PST 2014 armv7l Android/full/generic:4.0.4.0.4.0.4/OPENMASTER/eng.cltbld.20140508.192054:eng/test-keys
19:18:58     INFO -  CPU: arm
19:18:58     INFO -       0 CPUs
19:18:58     INFO -  Crash reason:  SIGSEGV
19:18:58     INFO -  Crash address: 0x0
19:18:58     INFO -  Thread 16 (crashed)
19:18:58     INFO -   0  libxul.so!mozilla::MediaDecoderStateMachine::GetClock() [MediaDecoderStateMachine.cpp:569b2343a616 : 2416 + 0x4]
19:18:58     INFO -       r4 = 0x44071f00    r5 = 0x00000000    r6 = 0x00031338    r7 = 0x00000000
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9bd0    lr = 0x41391f1d    pc = 0x41391f20
19:18:58     INFO -      Found by: given as instruction pointer in context
19:18:58     INFO -   1  libxul.so!mozilla::MediaDecoderStateMachine::StopPlayback() [MediaDecoderStateMachine.cpp:569b2343a616 : 1065 + 0x5]
19:18:58     INFO -       r4 = 0x44071f00    r5 = 0x44071f08    r6 = 0x42b5c4e4    r7 = 0x44066ff0
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9c00    pc = 0x413941c1
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -   2  libxul.so!mozilla::MediaDecoderStateMachine::RunStateMachine() [MediaDecoderStateMachine.cpp:569b2343a616 : 2294 + 0x5]
19:18:58     INFO -       r4 = 0x44071f00    r5 = 0x44071f08    r6 = 0x42b5c4e4    r7 = 0x44066ff0
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9c18    pc = 0x413970a5
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -   3  libxul.so!mozilla::MediaDecoderStateMachine::CallRunStateMachine() [MediaDecoderStateMachine.cpp:569b2343a616 : 2700 + 0x3]
19:18:58     INFO -       r4 = 0x00000000    r5 = 0x44071f00    r6 = 0x00000019    r7 = 0x4222298e
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9c78    pc = 0x4139713d
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -   4  libxul.so!mozilla::MediaDecoderStateMachine::TimeoutExpired(int) [MediaDecoderStateMachine.cpp:569b2343a616 : 2711 + 0x5]
19:18:58     INFO -       r4 = 0x00000001    r5 = 0x44071f00    r6 = 0x00000019    r7 = 0x4222298e
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9c90    pc = 0x413971d3
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -   5  libxul.so!mozilla::TimerEvent::Notify(nsITimer*) [MediaDecoderStateMachine.cpp:569b2343a616 : 2734 + 0xd]
19:18:58     INFO -       r4 = 0x445a34c0    r5 = 0x445a34c0    r6 = 0x00000001    r7 = 0x4222298e
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9cb0    pc = 0x4139721f
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -   6  libxul.so!nsTimerImpl::Fire() [nsTimerImpl.cpp:569b2343a616 : 558 + 0x9]
19:18:58     INFO -       r4 = 0x402fc4c0    r5 = 0x445a34c0    r6 = 0x00000001    r7 = 0x4222298e
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9cb8    pc = 0x4062bc21
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -   7  libxul.so!nsTimerEvent::Run() [nsTimerImpl.cpp:569b2343a616 : 639 + 0x5]
19:18:58     INFO -       r4 = 0x44a2d870    r5 = 0x000027bb    r6 = 0x00000000    r7 = 0x4222298e
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9d18    pc = 0x4062be0b
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -   8  libxul.so!nsThreadPool::Run() [nsThreadPool.cpp:569b2343a616 : 211 + 0x5]
19:18:58     INFO -       r4 = 0x445019a0    r5 = 0x00000000    r6 = 0x00000000    r7 = 0x4222298e
19:18:58     INFO -       r8 = 0x4221124b    r9 = 0x42211284   r10 = 0x422122bd    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9d40    pc = 0x4062ab19
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -   9  libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:569b2343a616 : 715 + 0x9]
19:18:58     INFO -       r4 = 0x40266380    r5 = 0x00000000    r6 = 0x449f9dd4    r7 = 0x449f9dd0
19:18:58     INFO -       r8 = 0x00000000    r9 = 0x449f9e0f   r10 = 0x402663bc    fp = 0x00000000
19:18:58     INFO -       sp = 0x449f9da0    pc = 0x40628f05
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -  10  libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:569b2343a616 : 263 + 0xd]
19:18:58     INFO -       r4 = 0x40266380    r5 = 0x00000000    r6 = 0x44a1f880    r7 = 0x44a1f898
19:18:58     INFO -       r8 = 0x43f4afa0    r9 = 0x42b5c4e4   r10 = 0x00020000    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9e08    pc = 0x405d61a5
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -  11  libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:569b2343a616 : 307 + 0x7]
19:18:58     INFO -       r4 = 0x44a1f890    r5 = 0x440bdc40    r6 = 0x44a1f880    r7 = 0x44a1f898
19:18:58     INFO -       r8 = 0x43f4afa0    r9 = 0x42b5c4e4   r10 = 0x00020000    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9e20    pc = 0x4080a821
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -  12  libxul.so!MessageLoop::RunInternal() [message_loop.cc:569b2343a616 : 229 + 0x7]
19:18:58     INFO -       r4 = 0x43f4afa0    r5 = 0x43f4afa0    r6 = 0x42b5c4e4    r7 = 0x00000000
19:18:58     INFO -       r8 = 0x449f9ea0    r9 = 0x40266390   r10 = 0x00020000    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9e58    pc = 0x407f5c33
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -  13  libxul.so!MessageLoop::Run() [message_loop.cc:569b2343a616 : 222 + 0x5]
19:18:58     INFO -       r4 = 0x43f4afa0    r5 = 0x43f4afa0    r6 = 0x42b5c4e4    r7 = 0x00000000
19:18:58     INFO -       r8 = 0x449f9ea0    r9 = 0x40266390   r10 = 0x00020000    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9e70    pc = 0x407f5c4b
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -  14  libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:569b2343a616 : 316 + 0x3]
19:18:58     INFO -       r4 = 0x40266380    r5 = 0x43f4afa0    r6 = 0x42b5c4e4    r7 = 0x00000000
19:18:58     INFO -       r8 = 0x449f9ea0    r9 = 0x40266390   r10 = 0x00020000    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9e88    pc = 0x40628387
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -  15  libnss3.so!_pt_root [ptthread.c:569b2343a616 : 212 + 0x5]
19:18:58     INFO -       r4 = 0x445bc600    r5 = 0x00000000    r6 = 0x42ee8760    r7 = 0x0000d960
19:18:58     INFO -       r8 = 0x00000000    r9 = 0x00000001   r10 = 0x00020000    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9ed0    pc = 0x42df255d
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -  16  libc.so!__thread_entry [pthread.c : 217 + 0x6]
19:18:58     INFO -       r4 = 0x449f9f00    r5 = 0x42df24b1    r6 = 0x445bc600    r7 = 0x00000078
19:18:58     INFO -       r8 = 0x42df24b1    r9 = 0x445bc600   r10 = 0x00020000    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9ef0    pc = 0x4005ee4c
19:18:58     INFO -      Found by: call frame info
19:18:58     INFO -  17  libc.so!pthread_create [pthread.c : 357 + 0xe]
19:18:58     INFO -       r4 = 0x449f9f00    r5 = 0x0000d960    r6 = 0xbed477b4    r7 = 0x00000078
19:18:58     INFO -       r8 = 0x42df24b1    r9 = 0x445bc600   r10 = 0x00020000    fp = 0x00000001
19:18:58     INFO -       sp = 0x449f9f00    pc = 0x4005e99c
19:18:58     INFO -      Found by: call frame info
PRLog   : 2014-05-09 02:11:07.722269 UTC - 55216[44d24080]: MediaDecoderReader::FindStartTime() audio=0
PRLog   : 2014-05-09 02:11:07.722678 UTC - 55216[44d24080]: Decoder=4457a500 Media start time is 0
PRLog   : 2014-05-09 02:11:07.724356 UTC - 55216[44d24080]: Decoder=4457a500 Media goes from 0 to 300104 (duration 300104) transportSeekable=1, mediaSeekable=1
PRLog   : 2014-05-09 02:11:07.725460 UTC - 55216[44d24080]: Decoder=4457a500 Changed state from DECODING_METADATA to DECODING
PRLog   : 2014-05-09 02:11:07.726443 UTC - 55216[44d24080]: Decoder=4457a500 CheckIfDecodeComplete NOT completed
PRLog   : 2014-05-09 02:11:07.729860 UTC - 55216[44d24080]: Decoder=4457a500 CheckIfDecodeComplete NOT completed
PRLog   : 2014-05-09 02:11:07.738108 UTC - 55216[44d24080]: Decoder=4457a500 StartPlayback()
PRLog   : 2014-05-09 02:11:07.739937 UTC - 1074377864[40222080]: Stream 44066d58 closed
PRLog   : 2014-05-09 02:11:07.846157 UTC - 55152[40266000]: Decoder=4457a500 Begun audio thread/loop
PRLog   : 2014-05-09 02:11:07.861380 UTC - 1074377864[40222080]: Stream 44067e88 feeding reader
PRLog   : 2014-05-09 02:11:07.861840 UTC - 1074377864[40222080]: Stream 440684c8 feeding reader
PRLog   : 2014-05-09 02:11:07.883775 UTC - 1074377864[40222080]: Decoder=4457a500 MetadataLoaded, channels=6 rate=48000 hasAudio=1 hasVideo=0
PRLog   : 2014-05-09 02:11:08.205160 UTC - 55280[440d0280]: Decoder=4457a500 CheckIfDecodeComplete completed
PRLog   : 2014-05-09 02:11:08.677241 UTC - 55152[40266000]: Decoder=4457a500 Reached audio stream end.
PRLog   : 2014-05-09 02:11:08.688040 UTC - 55152[40266000]: Decoder=4457a500 Audio stream finished playing, audio thread exit
PRLog   : 2014-05-09 02:11:08.689833 UTC - 55648[445bc600]: Decoder=4457a500 StopPlayback()
PRLog   : 2014-05-09 02:11:08.692361 UTC - 55648[445bc600]: Decoder=4457a500 mPlaybackRate=1.000000 mCurrentFrameTime=206104 clock_time=201528

It says "Media goes from 0 to 300104". It is strange that when it reaches play complete, mCurrentFrameTime is 206104 less than the end time which is 300104. Is it possible?
Flags: needinfo?(cpearce)
The actual timestamp at end could be less than the duration if the duration was an estimate (like for MP3) or the duration came from the files metadata (index or somesuch) and it was wrong.

But it looks like in this case you're playing a 6 channel audio file with duration ~ 300ms, so I'd guess you're playing content/media/test/bug495794.ogg. (I determined this using `oggz-info content/media/test/*.og* | grep "Audio-Channels: 6" -7`
Flags: needinfo?(cpearce)
So for Ogg, I'd only expect the actual decoded samples to be less than the duration if the ogg page granulepos was incorrectly labelled, or if it was originally correctly labelled, but the ogg file was oggz-chopped (split) such that the granulepos no longer reflects what can actually be decoded.
https://tbpl.mozilla.org/php/getParsedLog.php?id=39538074&tree=Try&full=1#error0

I keep the last 50 results of MediaDecoderStateMachine::GetAudioClock() and print them out when the assertion fails. (file: https://hg.mozilla.org/try/file/de245c12264d/content/media/MediaDecoderStateMachine.cpp#l2352)

Here is the log:
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 StopPlayback()
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 GetVideoStreamPosition pos=2275435 mPlayDuration=2235463 mBasePosition=0
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 mPlaybackRate=1.000000 mCurrentFrameTime=2290554 clock_time=2275435
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=2235463
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=2190617
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=2290554
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=2169587
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=2127707
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=2084928
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=2041790
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=2006470
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=1964860
2014-05-13 04:00:04.218000 UTC - 2488[284b8d08]: Decoder=276cbdf0 AudioClockTime=1921632

The last audio clock times are: 2169587 => 2290554 => 2190617 => 2235463. The audio clock time drifting can be observed on Windows and B2G emulator.

Is this a normal case?
Flags: needinfo?(rjesup)
https://tbpl.mozilla.org/php/getParsedLog.php?id=39546326&tree=Try&full=1#error3

23:47:45     INFO -  05-13 06:38:26.790   731   931 I PRLog   : 2014-05-13 06:38:26.795496 UTC - 55600[44162980]: Decoder=446b8100 GetVideoStreamPosition pos=205691 mPlayDuration=149104 mBasePosition=0
23:47:45     INFO -  05-13 06:38:26.790   731   931 I PRLog   : 2014-05-13 06:38:26.797567 UTC - 55600[44162980]: Decoder=446b8100 mPlaybackRate=1.000000 mCurrentFrameTime=206104 clock_time=205691
23:47:45     INFO -  05-13 06:38:26.790   731   931 I PRLog   : 2014-05-13 06:38:26.799514 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=149104
23:47:45     INFO -  05-13 06:38:26.800   731   931 I PRLog   : 2014-05-13 06:38:26.800205 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=149104
23:47:45     INFO -  05-13 06:38:26.800   731   931 I PRLog   : 2014-05-13 06:38:26.802766 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=206104
23:47:45     INFO -  05-13 06:38:26.800   731   931 I PRLog   : 2014-05-13 06:38:26.803571 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=206104
23:47:45     INFO -  05-13 06:38:26.800   731   931 I PRLog   : 2014-05-13 06:38:26.804275 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=137104
23:47:45     INFO -  05-13 06:38:26.800   731   931 I PRLog   : 2014-05-13 06:38:26.804988 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=187104
23:47:45     INFO -  05-13 06:38:26.800   731   931 I PRLog   : 2014-05-13 06:38:26.807455 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=194104
23:47:45     INFO -  05-13 06:38:26.800   731   931 I PRLog   : 2014-05-13 06:38:26.808131 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=171104
23:47:45     INFO -  05-13 06:38:26.800   731   931 I PRLog   : 2014-05-13 06:38:26.808800 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=176104
23:47:45     INFO -  05-13 06:38:26.810   731   931 I PRLog   : 2014-05-13 06:38:26.811487 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=176104
23:47:45     INFO -  05-13 06:38:26.810   731   931 I PRLog   : 2014-05-13 06:38:26.813067 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=151333
23:47:45     INFO -  05-13 06:38:26.810   731   931 I PRLog   : 2014-05-13 06:38:26.813821 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=153666
23:47:45     INFO -  05-13 06:38:26.810   731   931 I PRLog   : 2014-05-13 06:38:26.816001 UTC - 55600[44162980]: Decoder=446b8100 AudioClockTime=96000

The drifting is even worse on B2G emulator...
It looks like we have a race condition where the buffer filled by AudioStream::DataCallback() is not immediately consumed by the cubeb back-end and we might over adjust the position returned by cubeb_stream_get_position() in AudioStream::GetPositionInFramesUnlocked(). I think that might account for the audio clock time drifting.
Flags: needinfo?(kinetik)
Tracking time is tricky - and grabbing audio positions/buffer-depth from one spot to use in another or combine is especially tricky.  Especially if you don't lock.
Flags: needinfo?(rjesup)
(discussed on IRC, ni? me again or ping on IRC if you need me!)
Flags: needinfo?(kinetik)
Blocks: 903525
Fix the stream position adjustment algorithm in AudioStream::GetPositionInFramesUnlocked so it won't over-adjust the position and result in audio clock going backward.
Assignee: nobody → jwwang
Status: NEW → ASSIGNED
Attachment #8426148 - Flags: review?(kinetik)
Remove the assertion which is (to be) addressed in bug 998174.
Attachment #8426148 - Attachment is obsolete: true
Attachment #8426148 - Flags: review?(kinetik)
Attachment #8428467 - Flags: feedback?(rlin)
Attachment #8428467 - Flags: feedback?(bechen)
...did you mean to change reviewers?
Comment on attachment 8428467 [details] [diff] [review]
1008057_fix_AudioStreamClock-v2.patch

Hi Matthew, 
Our team has a process that a patch need a fb+, then it can set r? to real reviewer.
Please help to review that, thanks.
Attachment #8428467 - Flags: review?(kinetik)
Attachment #8428467 - Flags: feedback?(rlin)
Attachment #8428467 - Flags: feedback+
Ah okay, thanks for explaining! :-)
Comment on attachment 8428467 [details] [diff] [review]
1008057_fix_AudioStreamClock-v2.patch

Review of attachment 8428467 [details] [diff] [review]:
-----------------------------------------------------------------

::: content/media/AudioStream.cpp
@@ +794,5 @@
> +  // [mWrittenFramesPast+mLostFramesPast, mWrittenFramesPast+mLostFramesPast+mWrittenFramesLast+mLostFramesLast],
> +  // we will be able to adjust position precisely which should be the major case.
> +  // If |position| falls in [0, mWrittenFramesPast+mLostFramesPast), there will be an
> +  // error in the adjustment. However that is fine as long as we can ensure the
> +  // adjusted position is mono-increasing to avoid audio clock going backward.

Just a suggestion, now you divide the history into two parts. One is the latest frames, another is the the others. So is it better to use more entries to record this information?
Ex: Declare a fixed size nsTArray that that stores [1~N-4][N-3][N-2][N-1][N].
Of course, the size is depend on the probability of "error adjustment", it may vary from different backends or platform.

::: content/media/AudioStream.h
@@ +65,5 @@
>    // Get the current pitch preservation state.
>    // Called on the audio thread.
>    bool GetPreservesPitch();
>    // Get the number of frames written to the backend.
> +  int64_t GetWritten() { return mWritten; }

Where is the caller? Do we need this?
Attachment #8428467 - Flags: feedback?(bechen) → feedback+
Comment on attachment 8428467 [details] [diff] [review]
1008057_fix_AudioStreamClock-v2.patch

Review of attachment 8428467 [details] [diff] [review]:
-----------------------------------------------------------------

::: content/media/AudioStream.cpp
@@ +794,5 @@
> +  // [mWrittenFramesPast+mLostFramesPast, mWrittenFramesPast+mLostFramesPast+mWrittenFramesLast+mLostFramesLast],
> +  // we will be able to adjust position precisely which should be the major case.
> +  // If |position| falls in [0, mWrittenFramesPast+mLostFramesPast), there will be an
> +  // error in the adjustment. However that is fine as long as we can ensure the
> +  // adjusted position is mono-increasing to avoid audio clock going backward.

I was designing a generic algorithm to handle history of N entries (N >= 2) so that if we need more precise frame adjustment, we just need to increase the value of N. Later I concluded the flexibility was an overkill and decided to keep the code as simple/explicit as possible.

For the matter of how we store the history (array vs named variables), I think each element in the array should have the same semantics. For the case of N=2, we would put sum of frames from 1st to |N-1|th callbacks in array[0], and frames from Nth callback in array[1]. Then element 0 and 1 will have slightly different meanings where element 0 presents an aggregation while element 1 is a simple scalar.

Therefore, I prefer the code to be explicit and readable in such a case.

::: content/media/AudioStream.h
@@ +65,5 @@
>    // Get the current pitch preservation state.
>    // Called on the audio thread.
>    bool GetPreservesPitch();
>    // Get the number of frames written to the backend.
> +  int64_t GetWritten() { return mWritten; }

Good catch! It was used in my previous patch (https://bug1008057.bugzilla.mozilla.org/attachment.cgi?id=8426148) to check the position returned by cubeb_stream_get_position should never exceed the frames written to the audio backend (mAudioClock.GetWritten()). Since the assertion was removed (see comment 10), I should also remove the implementation for it is not used anyway.
Blocks: 1016730
Comment on attachment 8428467 [details] [diff] [review]
1008057_fix_AudioStreamClock-v2.patch

Review of attachment 8428467 [details] [diff] [review]:
-----------------------------------------------------------------

I think we're better off implementing this in libcubeb using an approach like the one described at http://bugs.winehq.org/show_bug.cgi?id=28039#c2 (and comment 3 and the linked post), which is more-or-less the same was what Randy asked about in the feedback.  I'll file a bug against libcubeb for that.

::: content/media/AudioStream.h
@@ +65,5 @@
>    // Get the current pitch preservation state.
>    // Called on the audio thread.
>    bool GetPreservesPitch();
>    // Get the number of frames written to the backend.
> +  int64_t GetWritten() { return mWritten; }

Remove the declaration too, it looks like it has never been implemented or called!
Attachment #8428467 - Flags: review?(kinetik) → review+
(In reply to Matthew Gregan [:kinetik] from comment #17)
> Randy asked about in the feedback.  I'll file a bug against libcubeb for

I mean Benjamin, sorry!
(In reply to Matthew Gregan [:kinetik] from comment #17)
> I think we're better off implementing this in libcubeb using an approach
> like the one described at http://bugs.winehq.org/show_bug.cgi?id=28039#c2
> (and comment 3 and the linked post), which is more-or-less the same was what
> Randy asked about in the feedback.  I'll file a bug against libcubeb for
> that.

Do you mean we can back out this patch when the implementation in libcubeb is done?
Yeah, but I don't know when that'll be.  I don't have time to work on libcubeb for the foreseeable future.
I see. I will still check in the patch for the time being to fix the assertion.
Yes, absolutely, that's why I r+ed it.  Your fix improves the current state a lot, and there's no point waiting for a perfect solution when we can improve things incrementally. :-)
Minor fix suggested in comment 17.
Attachment #8428467 - Attachment is obsolete: true
Attachment #8429907 - Flags: review+
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/758fb5c247c2
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla32
Blocks: 887628
See Also: → 1106698
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: