Hi,
Hope I did the decent thing to post this under my original thread.
I've been looking more into what is happening when changing between M2TS files in a MPLS playlist and what would cause the audio drop outs and now I'm stuck with knowledge of why the dropouts happen but not what to do about it.
Hopefully there's a dev/team member/enthusiast out there who might know what is happening or who to contact who might be able to figure it out or help me figure it.
So in short it appears that the DTS (timestamp?) value in packets retrieved by the DVDPlayer from the demux (ffmpeg?) after the file changes causes the audio/video queues to think they are full. This happens because the time duration between the front and back is large. And this is because of the DTS in packets from the new file.
Once this happens the queues become starved because DVDPlayer is not adding to them and eventually the audio is emptied causing a CSoftAEStream::Flush and then things get back in sync but only after a noticeable audio drop out (assuming noticeable audio at that time).
I added logging to capture the queues/DTS values and now I can see what the values are and why they cause a problem but I don't know where to go to fix it.
Code:
// KEY TO LINES
// The large decmial numbers are DTS
// Accepts data: Audio [1=accept data,0=not accept],[% full] video [1=accept data,0=not accept],[% full]
// CDVDPlayer::CheckContinuity -
// cur:[current DTS],
// pak:[packet DTS],
// diff:[cur - pak]
// CDVDMessageQueue([type])::[Get/Put] - put new data packet
// (l:[packets in queue],
// s:[size of packet Get/Put],
// ts:[sum all packet sizes],
// tf:[DTS front],
// tb:[DTA back])
// Just before the file change everything is kinda stable and here are the last reads for video and audio:
Code:
20:25:21 T:2824 DEBUG: Accepts data: Audio 1,82 video 1,88
20:25:21 T:2824 DEBUG: ProcessPacket IN
20:25:21 T:2824 DEBUG: Process video packet
20:25:21 T:2824 DEBUG: CDVDPlayer::CheckContinuity - cur:36175166.666667, pak:36216866.666667, diff:41700.000000
20:25:21 T:2824 DEBUG: CDVDMessageQueue(video)::Put - put new data packet(l:191,s:2342,ts:20001243,tf:36216866.666667,tb:28250577.777778)
20:25:21 T:2824 DEBUG: ProcessPacket OUT
20:25:22 T:2824 DEBUG: Accepts data: Audio 1,85 video 1,88
20:25:22 T:2824 DEBUG: ProcessPacket IN
20:25:22 T:2824 DEBUG: Process audio packet
20:25:22 T:2824 DEBUG: CDVDPlayer::CheckContinuity - cur:36312000.000000, pak:36322666.666667, diff:10666.666667
20:25:22 T:2824 DEBUG: CDVDMessageQueue(audio)::Put - put new data packet(l:637,s:3948,ts:2537204,tf:36322666.666667,tb:29528000.000000)
20:25:22 T:2824 DEBUG: ProcessPacket OUT
// The next packets come from the new file in order
Code:
20:25:22 T:2824 DEBUG: ProcessPacket IN
20:25:22 T:2824 DEBUG: Process video packet
20:25:22 T:2824 DEBUG: CDVDPlayer::CheckContinuity - cur:36216866.666667, pak:36258577.777778, diff:41711.111111
20:25:22 T:2824 DEBUG: CDVDMessageQueue(video)::Put - put new data packet(l:178,s:2359,ts:18222579,tf:36258577.777778,tb:28834500.000000)
20:25:22 T:2824 DEBUG: ProcessPacket OUT
20:25:22 T:2824 DEBUG: Accepts data: Audio 1,85 video 1,88
// This packet has a DTS(see pak:) that you wouldn't expected and don't see if the M2TS is a single file
20:25:22 T:2824 DEBUG: ProcessPacket IN
20:25:22 T:2824 DEBUG: Process video packet
20:25:22 T:2824 DEBUG: CDVDPlayer::CheckContinuity - cur:36258577.777778, pak:11608955.555556, diff:-24649622.222222
20:25:22 T:2824 DEBUG: CDVDPlayer::CheckContinuity - resync backward :2, prev:36258577.777778, curr:11608955.555556, diff:-24649622.222222
20:25:22 T:2824 DEBUG: CDVDMessageQueue(video)::Put - put new data packet(l:179,s:68926,ts:18291505,tf:36300277.777778,tb:28834500.000000)
20:25:22 T:2824 DEBUG: ProcessPacket OUT
20:25:22 T:2824 DEBUG: Accepts data: Audio 1,85 video 1,88
20:25:22 T:2824 DEBUG: ProcessPacket IN
20:25:22 T:2824 DEBUG: Process video packet
20:25:22 T:1444 DEBUG: CDVDMessageQueue(audio)::Get - asked for new data packet(l:631,s:3984,ts:2513300,tf:36322666.666667,tb:29592000.000000)
20:25:22 T:2824 DEBUG: CDVDPlayer::CheckContinuity - cur:36300277.777778, pak:36341988.888889, diff:41711.111111
20:25:22 T:2824 DEBUG: CDVDMessageQueue(video)::Put - put new data packet(l:180,s:89188,ts:18380693,tf:36341988.888889,tb:28834500.000000)
20:25:22 T:2824 DEBUG: ProcessPacket OUT
20:25:22 T:2824 DEBUG: Accepts data: Audio 1,84 video 1,88
// This packet has a DTS(see pak:) that you wouldn't expected and don't see if the M2TS is a single file also cur: was reset.
20:25:22 T:2824 DEBUG: ProcessPacket IN
20:25:22 T:2824 DEBUG: Process audio packet
20:25:22 T:2824 DEBUG: CDVDPlayer::CheckContinuity - cur:-4503599627370496.000000, pak:61024655.555556, diff:4503599688395152.000000
20:25:22 T:2824 DEBUG: CDVDMessageQueue(audio)::Put - put new data packet(l:628,s:3948,ts:2501312,tf:61024655.555556,tb:29634666.666667)
20:25:22 T:2824 DEBUG: ProcessPacket OUT
// Now we are broken
Code:
20:25:22 T:2824 DEBUG: Accepts data: Audio 0,100 video 1,88
// Some time later we've just about drained the queues
Code:
20:25:28 T:1088 DEBUG: CDVDMessageQueue(video)::Get - asked for new data packet(l:21,s:258110,ts:1464087,tf:36341988.888889,tb:35466122.222222)
20:25:29 T:1444 DEBUG: CDVDMessageQueue(audio)::Get - asked for new data packet(l:1,s:3948,ts:3948,tf:61024655.555556,tb:36322666.666667)
20:25:29 T:1444 DEBUG: CSoftAEStream::Flush
So is this an ffmpeg thing?
It's odd that the first video packet of the new file seems to have DTS(pak:) (on the first CDVDPlayer::CheckContinuity line) that looks correct but not the second.
If I change the code so that DVDPlayer can continue without regard to full queues I see that this large(61024655) DTS for packets(pak:) becomes the standard for both video and audio packets.
Also if I play the M2TS file directly it starts with a DTS(pak:) like 11608955 which is the first unexpected value in the logs above.
Ok, so I hope someone out there will hear this. It's taken a while.
Regards