search

huceke / omxplayer

omxplayer
GNU General Public License v2.0
520 stars 500 forks source link

Backward Timestamp Freezing GENERAL_RESYNC(-47612916688.888893, 0) #136

Open bashirg opened 11 years ago

bashirg commented 11 years ago

I am testing out a PVR addon with HLS streams and if a live stream has a backward timestamp while you are watching its fine it will compensate for it.. the problem occurs after you switch channels with the PVRmanager in Fullscreen mode. Any channel will freeze as if it cant compensate for the timestamps.. view full log below with channel switch output.

18:13:28 T:2779772000 DEBUG: COMXPlayer::CheckContinuity - resync forward :1, prev:50154666.666669, curr:47663109688.888893, diff:47612933688.888893

BUT If you change channel the backward timestamp will freeze all other channels - streams until you quit fullscreen and reset.

bashirg commented 11 years ago

full log:

18:12:43 T:2779772000 DEBUG: PVRManager - OpenLiveStream - opening live stream on channel 'test1' 18:12:43 T:2779772000 DEBUG: opening live stream on url 'http://x.x.x.x/pvrtest/test1/playlist.m3u8' 18:12:43 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:43 T:2779772000 DEBUG: Previous line repeats 3 times. 18:12:43 T:2779772000 DEBUG: PVRFile - Open - playback has started on filename pvr://channels/tv/All TV channels/102.pvr 18:12:43 T:2779772000 DEBUG: CDVDInputStreamPVRManager::Open - stream opened: http://x.x.x.x/pvrtest/test1/playlist.m3u8 18:12:43 T:2779772000 NOTICE: Creating Demuxer 18:12:43 T:2779772000 DEBUG: DllAvUtilBase: Using libavutil system library 18:12:43 T:2779772000 DEBUG: DllAvCodec: Using libavcodec system library 18:12:43 T:2779772000 DEBUG: DllAvFormat: Using libavformat system library 18:12:43 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:12:43 T:3041845248 DEBUG: Previous line repeats 3 times. 18:12:43 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:44 T:2779772000 DEBUG: Previous line repeats 3 times. 18:12:44 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:12:44 T:3041845248 DEBUG: Previous line repeats 1 times. 18:12:44 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:44 T:2779772000 DEBUG: Previous line repeats 4 times. 18:12:44 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] parser not found for codec none, packets or times may be invalid. 18:12:44 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:45 T:2779772000 DEBUG: Previous line repeats 4 times. 18:12:45 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] max_analyze_duration 5000000 reached at 5013333 18:12:45 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] Could not find codec parameters for stream 0 (Unknown: none ([21][0][0][0] / 0x0015)): unknown codec 18:12:45 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] Consider increasing the value for the 'analyzeduration' and 'probesize' options 18:12:45 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] Estimating duration from bitrate, this may be inaccurate 18:12:45 T:2779772000 DEBUG: Open - avformat_find_stream_info starting 18:12:45 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:45 T:2779772000 DEBUG: Previous line repeats 2 times. 18:12:45 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [hls,applehttp] max_analyze_duration 5000000 reached at 5013333 18:12:45 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [hls,applehttp] Could not find codec parameters for stream 0 (Unknown: none ([21][0][0][0] / 0x0015)): unknown codec 18:12:45 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [hls,applehttp] Consider increasing the value for the 'analyzeduration' and 'probesize' options 18:12:45 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [hls,applehttp] Estimating duration from bitrate, this may be inaccurate 18:12:45 T:2779772000 DEBUG: Open - av_find_stream_info finished 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Input #0, hls,applehttp, from 'http://x.x.x.x/pvrtest/test1/playlist.m3u8': 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Duration: 00:00:00.05, start: 47780.608000, bitrate: 13 kb/s 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Program 0 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Metadata: 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: variant_bitrate : 450000 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Stream #0:0: Unknown: none ([21][0][0][0] / 0x0015) 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Metadata: 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: variant_bitrate : 450000 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Stream #0:1: Video: h264 (High) ([27][0][0][0] / 0x001B), yuv420p, 544x480 [SAR 80:51 DAR 16:9], 14.99 fps, 29.97 tbr, 90k tbn, 59.94 tbc 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Metadata: 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: variant_bitrate : 450000 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Stream #0:2: Audio: aac ([15][0][0][0] / 0x000F), 48000 Hz, stereo, fltp, 96 kb/s 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: Metadata: 18:12:45 T:2779772000 INFO: ffmpeg[A5AFF460]: variant_bitrate : 450000 18:12:45 T:2779772000 NOTICE: Opening video stream: 1 source: 256 18:12:45 T:2757092448 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_RESET 18:12:45 T:2757092448 DEBUG: OMXClock::OMXStop 18:12:45 T:2779772000 NOTICE: Opening audio stream: 2 source: 256 18:12:45 T:2757092448 NOTICE: OMXClock using audio as reference 18:12:45 T:2779772000 DEBUG: DllBcm: Using omx system library 18:12:45 T:2757092448 DEBUG: OMXClock::OMXReset audio / video : 1 / 1 start audio / video : 1 / 1 wait mask 3 18:12:45 T:2779772000 DEBUG: DllAvUtilBase: Using libavutil system library 18:12:45 T:2779772000 DEBUG: DllAvCodec: Using libavcodec system library 18:12:45 T:2779772000 DEBUG: DllAvFormat: Using libswresample system library 18:12:45 T:2779772000 DEBUG: OMXClock::OMXSetSpeed 1 buffering 0 18:12:45 T:2779772000 DEBUG: COMXPlayer::SetCaching - caching state 2 18:12:45 T:2779772000 DEBUG: OMXClock::OMXSetSpeed 0 buffering 0 18:12:45 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:12:45 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::GENERAL_RESYNC(0.000000, 1) 18:12:45 T:2748703840 DEBUG: COMXAudio::Decode ADec : setStartTime 0.000000 18:12:45 T:2779772000 DEBUG: COMXPlayer::HandleMessages - player started 1 18:12:45 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:12:45 T:2757092448 DEBUG: Previous line repeats 2 times. 18:12:45 T:2757092448 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_RESYNC(0.000000, 0) 18:12:45 T:2757092448 INFO: COMXPlayerVideo - Stillframe left, switching to normal playback 18:12:45 T:2757092448 DEBUG: OMXVideo::Decode VDec : setStartTime 0.046000 18:12:45 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:45 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:12:45 T:2779772000 DEBUG: COMXPlayer::HandleMessages - player started 2 18:12:45 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:12:45 T:3041845248 DEBUG: Previous line repeats 12 times. 18:12:45 T:3041845248 DEBUG: ------ Window Init (DialogSeekBar.xml) ------ 18:12:45 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:12:45 T:3041845248 DEBUG: Previous line repeats 25 times. 18:12:45 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:45 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:12:45 T:2779772000 DEBUG: Previous line repeats 21 times. 18:12:45 T:2779772000 DEBUG: set caching from pvr to done. audio (1) = 11. video (1) = 10 18:12:45 T:2779772000 DEBUG: COMXPlayer::SetCaching - caching state 0 18:12:45 T:2779772000 DEBUG: OMXClock::OMXSetSpeed 1 buffering 0 18:12:45 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:12:45 T:2748703840 DEBUG: OMXClock::OMXAudioBufferStart 18:12:45 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:45 T:3041845248 DEBUG: Previous line repeats 1 times. 18:12:45 T:3041845248 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------ 18:12:45 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:46 T:2748703840 DEBUG: Previous line repeats 6 times. 18:12:46 T:2748703840 INFO: COMXPlayerAudio - Switching to normal playback 18:12:46 T:2748703840 DEBUG: OMXClock::OMXAudioBufferStop 18:12:46 T:2748703840 DEBUG: OMXClock::OMXSetSpeed 1 buffering 0 18:12:46 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:47 T:2779772000 DEBUG: Previous line repeats 24 times. 18:12:47 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:12:47 T:3041845248 DEBUG: Previous line repeats 1 times. 18:12:47 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:57 T:2779772000 DEBUG: Previous line repeats 224 times. 18:12:57 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:12:57 T:3041845248 DEBUG: Previous line repeats 1 times. 18:12:57 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:12:57 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:12:57 T:3041845248 DEBUG: Previous line repeats 1 times. 18:12:57 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:07 T:2779772000 DEBUG: Previous line repeats 200 times. 18:13:07 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:07 T:3041845248 DEBUG: Previous line repeats 1 times. 18:13:07 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:17 T:2779772000 DEBUG: Previous line repeats 218 times. 18:13:17 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:17 T:3041845248 DEBUG: Previous line repeats 3 times. 18:13:17 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:27 T:2779772000 DEBUG: Previous line repeats 209 times. 18:13:27 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:27 T:3041845248 DEBUG: Previous line repeats 1 times. 18:13:27 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:27 T:2779772000 DEBUG: Previous line repeats 1 times. 18:13:27 T:2779772000 DEBUG: ffmpeg[A5AFF460]: skipping 2 segments ahead, expired from playlists 18:13:27 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:27 T:3041845248 DEBUG: Previous line repeats 1 times. 18:13:27 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:28 T:2779772000 DEBUG: Previous line repeats 7 times. 18:13:28 T:2779772000 DEBUG: COMXPlayer::CheckContinuity - resync forward :1, prev:50154666.666669, curr:47663109688.888893, diff:47612933688.888893 18:13:28 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:37 T:2779772000 DEBUG: Previous line repeats 186 times. 18:13:37 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:37 T:3041845248 DEBUG: Previous line repeats 3 times. 18:13:37 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:47 T:2779772000 DEBUG: Previous line repeats 186 times. 18:13:47 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:47 T:3041845248 DEBUG: Previous line repeats 1 times. 18:13:47 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:47 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:47 T:3041845248 DEBUG: Previous line repeats 1 times. 18:13:47 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:57 T:2779772000 DEBUG: Previous line repeats 225 times. 18:13:57 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:57 T:3041845248 DEBUG: Previous line repeats 1 times. 18:13:57 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:13:57 T:2779772000 DEBUG: Previous line repeats 1 times. 18:13:57 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:13:57 T:3041845248 DEBUG: Previous line repeats 1 times. 18:13:57 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:07 T:2779772000 DEBUG: Previous line repeats 232 times. 18:14:07 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:14:07 T:3041845248 DEBUG: Previous line repeats 1 times. 18:14:07 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:07 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:14:07 T:3041845248 DEBUG: Previous line repeats 1 times. 18:14:07 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:17 T:2779772000 DEBUG: Previous line repeats 216 times. 18:14:17 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:14:18 T:3041845248 DEBUG: Previous line repeats 3 times. 18:14:18 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:23 T:2958500960 DEBUG: Previous line repeats 116 times. 18:14:23 T:2958500960 DEBUG: CecLogMessage - >> 01:44:31 18:14:23 T:2958500960 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): user control pressed (44) 18:14:23 T:2958500960 DEBUG: CecLogMessage - key pressed: channel down (31) 18:14:23 T:2958500960 DEBUG: PushCecKeypress - received key d3 duration 0 18:14:23 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:23 T:3041845248 DEBUG: OnKey: rightshift (d3) pressed, action is SkipPrevious 18:14:23 T:2779772000 DEBUG: CGUIInfoManager::SetCurrentMovie(pvr://channels/tv/All TV channels/101.pvr) 18:14:23 T:3041845248 DEBUG: ------ Window Init (DialogSeekBar.xml) ------ 18:14:23 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:23 T:2958500960 DEBUG: Previous line repeats 3 times. 18:14:23 T:2958500960 DEBUG: CecLogMessage - >> 01:8b:31 18:14:23 T:2958500960 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): vendor remote button up (8B) 18:14:23 T:2958500960 DEBUG: CecLogMessage - key released: channel down (31) 18:14:23 T:2958500960 DEBUG: PushCecKeypress - received key d3 duration 237 18:14:23 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:25 T:2748703840 DEBUG: Previous line repeats 40 times. 18:14:25 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::GENERAL_FLUSH 18:14:25 T:2748703840 DEBUG: OMXClock::OMXStop 18:14:25 T:2757092448 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_FLUSH 18:14:25 T:2748703840 NOTICE: OMXClock using audio as reference 18:14:25 T:2748703840 DEBUG: OMXClock::OMXReset audio / video : 1 / 1 start audio / video : 1 / 1 wait mask 3 18:14:25 T:2757092448 DEBUG: OMXClock::OMXStop 18:14:25 T:2757092448 NOTICE: OMXClock using audio as reference 18:14:25 T:2757092448 DEBUG: OMXClock::OMXReset audio / video : 1 / 1 start audio / video : 1 / 1 wait mask 3 18:14:25 T:2757092448 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE 18:14:25 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE 18:14:25 T:2779772000 DEBUG: COMXPlayer::SetCaching - caching state 3 18:14:25 T:2779772000 DEBUG: OMXClock::OMXSetSpeed 0 buffering 0 18:14:25 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:14:25 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:26 T:3041845248 DEBUG: Previous line repeats 5 times. 18:14:26 T:3041845248 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------ 18:14:26 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:26 T:2779772000 DEBUG: Previous line repeats 1 times. 18:14:26 T:2779772000 DEBUG: CDVDInputStreamPVRManager::Close - stream closed 18:14:26 T:2779772000 DEBUG: PVRManager - OpenLiveStream - opening live stream on channel 'test2' 18:14:26 T:2779772000 DEBUG: opening live stream on url 'http://x.x.x.x/pvrtest/test2/playlist.m3u8' 18:14:26 T:2779772000 DEBUG: PVRFile - Open - playback has started on filename pvr://channels/tv/All TV channels/101.pvr 18:14:26 T:2779772000 DEBUG: CDVDInputStreamPVRManager::Open - stream opened: http://x.x.x.x/pvrtest/test2/playlist.m3u8 18:14:26 T:2779772000 NOTICE: Creating Demuxer 18:14:26 T:2779772000 DEBUG: DllAvUtilBase: Using libavutil system library 18:14:26 T:2779772000 DEBUG: DllAvCodec: Using libavcodec system library 18:14:26 T:2779772000 DEBUG: DllAvFormat: Using libavformat system library 18:14:26 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:14:26 T:3041845248 DEBUG: Previous line repeats 1 times. 18:14:26 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:26 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:14:26 T:3041845248 DEBUG: Previous line repeats 1 times. 18:14:26 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:27 T:2779772000 DEBUG: Previous line repeats 3 times. 18:14:27 T:2779772000 DEBUG: ffmpeg[A5AFF460]: Using network protocols without global network initialization. Please use avformat_network_init(), this will become mandatory later. 18:14:27 T:3041845248 DEBUG: Previous line repeats 1 times. 18:14:27 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:27 T:2779772000 DEBUG: Previous line repeats 4 times. 18:14:27 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] parser not found for codec none, packets or times may be invalid. 18:14:27 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:28 T:2779772000 DEBUG: Previous line repeats 6 times. 18:14:28 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] max_analyze_duration 5000000 reached at 5013333 18:14:28 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] Could not find codec parameters for stream 0 (Unknown: none ([21][0][0][0] / 0x0015)): unknown codec 18:14:28 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] Consider increasing the value for the 'analyzeduration' and 'probesize' options 18:14:28 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [mpegts] Estimating duration from bitrate, this may be inaccurate 18:14:28 T:2779772000 DEBUG: Open - avformat_find_stream_info starting 18:14:28 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:28 T:2779772000 DEBUG: Previous line repeats 2 times. 18:14:28 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [hls,applehttp] max_analyze_duration 5000000 reached at 5013333 18:14:28 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [hls,applehttp] Could not find codec parameters for stream 0 (Unknown: none ([21][0][0][0] / 0x0015)): unknown codec 18:14:28 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [hls,applehttp] Consider increasing the value for the 'analyzeduration' and 'probesize' options 18:14:28 T:2779772000 DEBUG: ffmpeg[A5AFF460]: [hls,applehttp] Estimating duration from bitrate, this may be inaccurate 18:14:28 T:2779772000 DEBUG: Open - av_find_stream_info finished 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Input #0, hls,applehttp, from 'http://x.x.x.x/pvrtest/test2/playlist.m3u8': 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Duration: 00:00:00.09, start: 47880.704000, bitrate: 7 kb/s 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Program 0 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Metadata: 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: variant_bitrate : 450000 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Stream #0:0: Unknown: none ([21][0][0][0] / 0x0015) 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Metadata: 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: variant_bitrate : 450000 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Stream #0:1: Video: h264 (High) ([27][0][0][0] / 0x001B), yuv420p, 544x480 [SAR 80:51 DAR 16:9], 14.99 fps, 29.97 tbr, 90k tbn, 59.94 tbc 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Metadata: 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: variant_bitrate : 450000 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Stream #0:2: Audio: aac ([15][0][0][0] / 0x000F), 48000 Hz, stereo, fltp, 111 kb/s 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: Metadata: 18:14:28 T:2779772000 INFO: ffmpeg[A5AFF460]: variant_bitrate : 450000 18:14:28 T:2779772000 NOTICE: Opening video stream: 1 source: 256 18:14:28 T:2757092448 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_RESET 18:14:28 T:2757092448 DEBUG: OMXClock::OMXStop 18:14:28 T:2757092448 NOTICE: OMXClock using audio as reference 18:14:28 T:2757092448 DEBUG: OMXClock::OMXReset audio / video : 1 / 1 start audio / video : 1 / 1 wait mask 3 18:14:28 T:2779772000 NOTICE: Opening audio stream: 2 source: 256 18:14:28 T:2779772000 DEBUG: DllBcm: Using omx system library 18:14:28 T:2779772000 DEBUG: DllAvUtilBase: Using libavutil system library 18:14:28 T:2779772000 DEBUG: DllAvCodec: Using libavcodec system library 18:14:28 T:2779772000 DEBUG: DllAvFormat: Using libswresample system library 18:14:28 T:2779772000 DEBUG: OMXClock::OMXSetSpeed 1 buffering 0 18:14:28 T:2779772000 DEBUG: COMXPlayer::SetCaching - caching state 2 18:14:28 T:2779772000 DEBUG: OMXClock::OMXSetSpeed 0 buffering 0 18:14:28 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:14:28 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::GENERAL_RESYNC(-47612933688.888893, 1) 18:14:28 T:2748703840 DEBUG: COMXAudio::Decode ADec : setStartTime 0.000000 18:14:28 T:2779772000 DEBUG: COMXPlayer::HandleMessages - player started 1 18:14:28 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:14:28 T:2757092448 DEBUG: Previous line repeats 2 times. 18:14:28 T:2757092448 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_RESYNC(-47612916688.888893, 0) 18:14:28 T:2757092448 INFO: COMXPlayerVideo - Stillframe left, switching to normal playback 18:14:28 T:2757092448 DEBUG: OMXVideo::Decode VDec : setStartTime -47612.850689 18:14:28 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:28 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:14:28 T:2779772000 DEBUG: COMXPlayer::HandleMessages - player started 2 18:14:28 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:14:28 T:3041845248 DEBUG: Previous line repeats 8 times. 18:14:28 T:3041845248 DEBUG: ------ Window Init (DialogSeekBar.xml) ------ 18:14:28 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:14:28 T:3041845248 DEBUG: Previous line repeats 24 times. 18:14:28 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:28 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:14:28 T:2779772000 DEBUG: Previous line repeats 25 times. 18:14:28 T:2779772000 DEBUG: set caching from pvr to done. audio (1) = 11. video (1) = 10 18:14:28 T:2779772000 DEBUG: COMXPlayer::SetCaching - caching state 0 18:14:28 T:2779772000 DEBUG: OMXClock::OMXSetSpeed 1 buffering 0 18:14:28 T:2748703840 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 18:14:28 T:2748703840 DEBUG: OMXClock::OMXAudioBufferStart 18:14:28 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:28 T:3041845248 DEBUG: Previous line repeats 1 times. 18:14:28 T:3041845248 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------ 18:14:28 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:29 T:2748703840 DEBUG: Previous line repeats 5 times. 18:14:29 T:2748703840 INFO: COMXPlayerAudio - Switching to normal playback 18:14:29 T:2748703840 DEBUG: OMXClock::OMXAudioBufferStop 18:14:29 T:2748703840 DEBUG: OMXClock::OMXSetSpeed 1 buffering 0 18:14:29 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:34 T:2757092448 DEBUG: Previous line repeats 85 times. 18:14:34 T:2757092448 INFO: COMXPlayerVideo - Stillframe detected, switching to forced 29.970030 fps 18:14:34 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:59 T:2958500960 DEBUG: Previous line repeats 224 times. 18:14:59 T:2958500960 DEBUG: CecLogMessage - >> 01:44:20 18:14:59 T:2958500960 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): user control pressed (44) 18:14:59 T:2958500960 DEBUG: CecLogMessage - key pressed: 0 (20) 18:14:59 T:2958500960 DEBUG: PushCecKeypress - received key cf duration 0 18:14:59 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:59 T:3041845248 DEBUG: OnKey: 207 (cf) pressed, action is AudioDelay 18:14:59 T:3041845248 DEBUG: ------ Window Init (DialogSlider.xml) ------ 18:14:59 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:14:59 T:2958500960 DEBUG: Previous line repeats 1 times. 18:14:59 T:2958500960 DEBUG: CecLogMessage - >> 01:8b:20 18:14:59 T:2958500960 DEBUG: CecLogMessage - >> TV (0) -> Recorder 1 (1): vendor remote button up (8B) 18:14:59 T:2958500960 DEBUG: CecLogMessage - key released: 0 (20) 18:14:59 T:2958500960 DEBUG: PushCecKeypress - received key cf duration 342 18:14:59 T:3041845248 DEBUG: PrepareNextRender no buffer, out: 0, current: 0, display: 4 18:15:02 T:2958500960 DEBUG: Previous line repeats 29 times. 18:15:02 T:2958500960 DEBUG: CecLogMessage - >> 01:44:03

After this point only a Stop will reset OMXplayer so it will resync.. I see it attempts to resync and flush but it seems the timestamps are too far behind.. How could we compensate for these timestamps since they originate from terrestrial mpegts dvb streams? This happens with HTTP Mpegts - RTSP - and RTMP

bashirg commented 11 years ago

Good news.. by increasing GPU Video buffers to 120 and data chunk size to 20 * 1024 * 1024 and audio buffer to 20 seconds Internet streams now play flawlessly.

The issue with timestamps that are too far behind still exists. I have noticed if you stop a video and play a new stream it is always synced that issue arises when you switch channels and the timestamps of last watched stream and new streams are too far off.

In the logs every time you start a new stream setspeed is always equal to 1000. When you switch channels that doesnt happen. I want to try to force this when a channel switch is performed. Im sure this would solve the issue.

OpenLiveStream: (new stream always in sync) 12:49:44 T:2831897696 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 12:49:44 T:2731537504 DEBUG: OMXClock::OMXSetSpeed 1 buffering 0 12:49:44 T:2831897696 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 12:49:44 T:2731537504 DEBUG: COMXPlayer - CDVDMsg::PLAYER_SETSPEED speed : 1000 12:49:44 T:2831897696 DEBUG: COMXPlayerAudio - CDVDMsg::GENERAL_RESYNC(0.000000, 1) 12:49:44 T:2811229280 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_RESYNC(10332.999998, 0) 12:49:44 T:2811229280 INFO: COMXPlayerVideo - Stillframe left, switching to normal playback 12:49:44 T:2811229280 DEBUG: OMXVideo::Decode VDec : setStartTime 0.110333

Channel switch log: (wil go out of sync if timestamps are too far behind)

12:52:21 T:2831897696 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 12:52:21 T:2831897696 DEBUG: COMXPlayerAudio - CDVDMsg::GENERAL_RESYNC(0.000000, 1) 12:52:21 T:2831897696 DEBUG: COMXAudio::Decode ADec : setStartTime 0.000000 12:52:21 T:2731537504 DEBUG: COMXPlayer::HandleMessages - player started 1 12:52:21 T:2811229280 DEBUG: Previous line repeats 1 times. 12:52:21 T:2811229280 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_RESYNC(0.000000, 0) 12:52:21 T:2811229280 INFO: COMXPlayerVideo - Stillframe left, switching to normal playback 12:52:21 T:2811229280 DEBUG: OMXVideo::Decode VDec : setStartTime 0.048333

popcornmix commented 11 years ago

Are you able to produce a video file (e.g. through recording live tv with a channel change) that suffers from the timestamp problem? That may be easier to debug.

bashirg commented 11 years ago

how about i give you a live stream with this happening live.. if not then yes i will give you a .ts file with timestamps far behind..

popcornmix commented 11 years ago

I'm going to guess that connecting to a live stream over the internet is going to introduce more problems. The bitrate of live tv streams tends to be pretty high.

I think a file that reliably stalls would be better.

bashirg commented 11 years ago

no problem where can i send it..

popcornmix commented 11 years ago

Can you use dropbox to host it? (or any filehosting site).

bashirg commented 11 years ago

yes ill setup dropbox now... at the 41.826 second mark the pts-dts get reset.. here is packet snippet

[PACKET] codec_type=audio stream_index=1 pts=3764400 pts_time=41.826667 dts=3764400 dts_time=41.826667 duration=1920 duration_time=0.021333 convergence_duration=N/A convergence_duration_time=N/A size=293 pos=N/A flags=K [/PACKET] [PACKET] codec_type=audio stream_index=1 pts=6052026032 pts_time=67244.733689 dts=6052026032 dts_time=67244.733689 duration=1920 duration_time=0.021333 convergence_duration=N/A convergence_duration_time=N/A size=33 pos=4601864 flags=K [/PACKET]

bashirg commented 11 years ago

https://www.dropbox.com/s/81wx9ut5rq16m4r/ebru.tar

the streams are only 700k.. if you'd like to try it live let me know..

popcornmix commented 11 years ago

Does this hang for you at 41 seconds? I've tried it with command line omxplayer and xbmc and both played it until end (the horses and "get along there")

(my xbmc has some local mods I'm working on, but nothing specifically to fix this).

bashirg commented 11 years ago

omxplayer plays this fine.. the problem occurs when fullscreen video is playing in the pvrmanager and you switch to another stream. It seems to take the last known timestamp and apply it to next stream.

It stalls with GENERAL_RESYNC(-47612916688.888893, 0) -- setStartTime -47612.850689

if omxplayer can imitate the flush and resync when opening a new stream Im sure this wouldnt occur.

can you replicate pvr demo with this .ts file and another video in the PVRdemo xml file?

bashirg commented 11 years ago

If I flushed the buffers before switching channels wouldnt that effectively remove all video audio data from the buffers as if this was a new stream with no timestamps left in the buffer??

    FlushBuffers(true);

---------------------------omxplayer code--------------------------------------------------------- OMXPlayer.cpp:

else if (pMsg->IsType(CDVDMsg::PLAYER_CHANNEL_SELECT_NUMBER) && m_messenger.GetPacketCount(CDVDMsg::PLAYER_CHANNEL_SELECT_NUMBER) == 0) { FlushBuffers(false); CDVDInputStream::IChannel* input = dynamic_castCDVDInputStream::IChannel(m_pInputStream); if(input && input->SelectChannelByNumber(static_cast<CDVDMsgInt>(pMsg)->m_value)) {

popcornmix commented 11 years ago

FlushBuffers(true) may well fix it (I'm not completely sure what the queued parameter is meant to mean)

But I think there may be a bigger issue here where an unfortunate jump in timestamps (which can occur in any ts file) may cause the playback to stall. I was hoping for an example file that provoked that behaviour and to fix that.

bashirg commented 11 years ago

omxplayer is great it wont stall... unless... you replicate my environment then i guarantee you will see many stalls that are fixable if a flush/resync is done..

Off topic (a ts file that will 100% cause out of sync audio) i will send you another .ts file that will definitely generate out of sync audio.. this is caused by bad weather.. or packet loss.. the timestamps keep jumping and every time this will cause audio/video desync.

bashirg commented 11 years ago

popcornmix: how can i reset timestamps to 0 on channel switch and not use last known timestamp? flushing the buffers didn't work..

popcornmix commented 11 years ago

The GPU treats audio as the clock master. If audio packets have approximately the correct timestamps, then they will be played. If there is a jump in audio timestamp of more than 50ms, the clock will be reset to that timestamp. Video frames will be played according to audio clock time.

So, as long as fifos have been flushed of packets, and new video and audio timestamps are similar, it will just work (from GPU's point of view). There could be a problem if audio and video have unrelated timestamps.

I think the failure is happening in omxplayer itself, but I'm afraid I don't know where (possibly the buffering/stalling state machine).

bashirg commented 11 years ago

I deleted that comment because i tested the source and it still didnt work..

Can you give me an idea how I can flush the timestamps when switching channels. Im clueless.. But it should be the same as when you open a new stream.

popcornmix commented 11 years ago

If you want to prove if it is a timestamp issue, you could try adding: dts = pts = DVD_NOPTS_VALUE; to COMXAudio::AddPackets and COMXVideo::Decode (e.g. first line inside each of those functions).

I think GPU will happily play them (although quite likely will lose sync between video and audio).

bashirg commented 11 years ago

the COMXAudio::AddPackets function seems to have been commented out in omxplayer shipping with xbmc-12.1 .

I just got a black screen hehe..

thnx popcornmix.. ill post a video tonite with some strange timestamp issues that you might find interesting..

bashirg commented 11 years ago

im about to try rbej's branch to see if it solves these issues.. considering that you think its the buffering/stalling machine this might do the job Ill let you know.

bashirg commented 11 years ago

tried rbejs branch.. and it didnt work... there is definitely a timestamp handling issue in omxplayer... tried exact same setup with ubuntu dvdplayer it does not freeze on backward timestamps.. also tried gbox amlogic xbmc 12.0 frodo linux and same it does not freeze...

One thing though i've noticed is that dvdplayer always sets the speed to 1000 when switching channels within PVRManager.. OMX doesnt.. at least thats whats being printed out in the logs..

01:30:30 T:1399211104 DEBUG: CAMLCodec::SetSpeed, speed(0) 01:30:30 T:1399211104 DEBUG: Previous line repeats 1 times. 01:30:30 T:1399211104 DEBUG: CAMLCodec::SetSpeed, speed(1000) 01:30:30 T:1399211104 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(29421999.666667, 0) 01:30:30 T:1399211104 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback 01:30:30 T:1316062304 DEBUG: CDVDPlayer::HandleMessages - player started 2

i hope we will find a solution .. i really like the pi and omxplayer.. keep up the good work popcornmix.. let me know if i can help you in any way.