Bug 1768699 Comment 5 Edit History

Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.

Okay, now I can reproduce the issue.

The first output sample size change happens on `4000000`.
```
2022-05-19 21:00:04.683000 UTC - [Child 24144: MediaSupervisor #3]: D/MediaFormatReader MediaFormatReader[28b008f1900] ::ReturnOutput: Resolved data promise for Video [4000000, 4033333]
2022-05-19 21:00:04.683000 UTC - [Child 24144: MediaSupervisor #3]: D/MediaFormatReader MediaFormatReader[28b008f1900] ::ReturnOutput: change of video display size (720x720->220x220)
```
Before that, we received the id change and Reddit started feeding data from `4000000`
```
2022-05-19 20:59:59.024000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaFormatReader MediaFormatReader[28b008f1900] ::HandleDemuxedSamples: Video stream id changed from:4294967295 to:0

// some other logs

2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: V/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::GetBuffered: intersection=[(0.000000, 4.000000)]
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: V/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::GetBuffered: currentValue=[(0.000000, 4.000000)]
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::AppendBuffer: AppendBuffer(ArrayBuffer)
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::AppendData: AppendData(aLength=107109)
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource TrackBuffersManager[28b077ed000] ::EvictData: currentTime=0 buffered=1233kB, eviction threshold=102400kB, evict=-101061kB canevict=0kB
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::QueueAsyncSimpleEvent: Queuing event 'updatestart'
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource TrackBuffersManager[28b077ed000] ::AppendData: Appending 107109 bytes
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSource TrackBuffersManager[28b077ed000] ::ProcessTasks: Process task 'AppendBuffer'
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::IsInitSegmentPresent: aLength=107109 [003a8]
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: V/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::Init: Checking atom:'moof' @ 0
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: V/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::Init: Checking atom:'moof' @ 0
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: V/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::Init: Checking atom:'mdat' @ 936
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSource TrackBuffersManager[28b077ed000] ::SetAppendState: AppendState changed from WAITING_FOR_SEGMENT to PARSING_MEDIA_SEGMENT
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::IsInitSegmentPresent: aLength=107109 [003a8]
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: V/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::Init: Checking atom:'moof' @ 0
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::ParseStartAndEndTimestamps: [4000000, 7500000]
2022-05-19 20:59:59.204000 UTC - [Child 24144: Main Thread]: D/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::DispatchSimpleEvent: Dispatch event 'updatestart'
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSource TrackBuffersManager[28b077ed000] ::OnVideoDemuxCompleted: 105 video samples demuxed
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4000000,4033333] (adjusted:[4000000,4033333]), dts:4000000, duration:33333, kf:1)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4033333,4066666] (adjusted:[4033333,4066666]), dts:4033333, duration:33333, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4066666,4100000] (adjusted:[4066666,4100000]), dts:4066666, duration:33334, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4100000,4133333] (adjusted:[4100000,4133333]), dts:4100000, duration:33333, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4133333,4166666] (adjusted:[4133333,4166666]), dts:4133333, duration:33333, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4166666,4200000] (adjusted:[4166666,4200000]), dts:4166666, duration:33334, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4200000,4233333] (adjusted:[4200000,4233333]), dts:4200000, duration:33333, kf:0)
```
I checked the profiled result again, and I didn't notice that we were sending any suspicious events which would cause Reddit to append low resolution video. But I did notice that there were two event callback took much times, they are `mouse up` and `play`.  So my guess is that there might be some bug in their play event handler so some where, causing Reddit sending low resolution video to us.

I will ask Reddit to see if they could help us identify where the problem is.
Okay, now I can reproduce the issue.

The first output sample size change happens on `4000000`.
```
2022-05-19 21:00:04.683000 UTC - [Child 24144: MediaSupervisor #3]: D/MediaFormatReader MediaFormatReader[28b008f1900] ::ReturnOutput: Resolved data promise for Video [4000000, 4033333]
2022-05-19 21:00:04.683000 UTC - [Child 24144: MediaSupervisor #3]: D/MediaFormatReader MediaFormatReader[28b008f1900] ::ReturnOutput: change of video display size (720x720->220x220)
```
Before that, we received the id change and Reddit started feeding data from `4000000`
```
2022-05-19 20:59:59.024000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaFormatReader MediaFormatReader[28b008f1900] ::HandleDemuxedSamples: Video stream id changed from:4294967295 to:0

// some other logs

2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: V/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::GetBuffered: intersection=[(0.000000, 4.000000)]
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: V/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::GetBuffered: currentValue=[(0.000000, 4.000000)]
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::AppendBuffer: AppendBuffer(ArrayBuffer)
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::AppendData: AppendData(aLength=107109)
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource TrackBuffersManager[28b077ed000] ::EvictData: currentTime=0 buffered=1233kB, eviction threshold=102400kB, evict=-101061kB canevict=0kB
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::QueueAsyncSimpleEvent: Queuing event 'updatestart'
2022-05-19 20:59:59.202000 UTC - [Child 24144: Main Thread]: D/MediaSource TrackBuffersManager[28b077ed000] ::AppendData: Appending 107109 bytes
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSource TrackBuffersManager[28b077ed000] ::ProcessTasks: Process task 'AppendBuffer'
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::IsInitSegmentPresent: aLength=107109 [003a8]
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: V/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::Init: Checking atom:'moof' @ 0
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: V/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::Init: Checking atom:'moof' @ 0
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: V/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::Init: Checking atom:'mdat' @ 936
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSource TrackBuffersManager[28b077ed000] ::SetAppendState: AppendState changed from WAITING_FOR_SEGMENT to PARSING_MEDIA_SEGMENT
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::IsInitSegmentPresent: aLength=107109 [003a8]
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: V/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::Init: Checking atom:'moof' @ 0
2022-05-19 20:59:59.203000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples MP4ContainerParser[28b06867040] (video/mp4;codecs="avc1.4D401E")::ParseStartAndEndTimestamps: [4000000, 7500000]
2022-05-19 20:59:59.204000 UTC - [Child 24144: Main Thread]: D/MediaSource dom::SourceBuffer[28b06706bb0] (video/mp4;codecs="avc1.4D401E")::DispatchSimpleEvent: Dispatch event 'updatestart'
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSource TrackBuffersManager[28b077ed000] ::OnVideoDemuxCompleted: 105 video samples demuxed
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4000000,4033333] (adjusted:[4000000,4033333]), dts:4000000, duration:33333, kf:1)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4033333,4066666] (adjusted:[4033333,4066666]), dts:4033333, duration:33333, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4066666,4100000] (adjusted:[4066666,4100000]), dts:4066666, duration:33334, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4100000,4133333] (adjusted:[4100000,4133333]), dts:4100000, duration:33333, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4133333,4166666] (adjusted:[4133333,4166666]), dts:4133333, duration:33333, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4166666,4200000] (adjusted:[4166666,4200000]), dts:4166666, duration:33334, kf:0)
2022-05-19 20:59:59.205000 UTC - [Child 24144: MediaSupervisor #2]: D/MediaSourceSamples TrackBuffersManager[28b077ed000] ::ProcessFrames: Processing video/avc frame [4200000,4233333] (adjusted:[4200000,4233333]), dts:4200000, duration:33333, kf:0)
```
I checked the profiled result again, and I didn't notice that we were sending any suspicious events which would cause Reddit to append low resolution video. But I did notice that there were two event callback took much times, they are `mouse up` and `play`.  So my guess is that there might be some bug in their play event handler or some where, which causes Reddit sending low resolution video to us.

I will ask Reddit to see if they could help us identify where the problem is.

Back to Bug 1768699 Comment 5