2016-01-31, 00:23
Im playing videos via smb share. Sometimes I experience playback freeze for a few seconds and then kodi stops as like I pressed stop button. I resume playback and it works fine again. So I turned on debug log and reproduced the issue. Here is the fragment from the moment playback froze.
Reproduced with OpenELEC-Generic.x86_64-7.0-devel-20160129204252-r21994-g8628410.
Code:
22:16:38 T:140625725617920 NOTICE: CDVDMessageQueue::GetLevel() - can't determine level
22:16:38 T:140625725617920 NOTICE: CVideoPlayerAudio::Process - stream stalled
22:16:39 T:140625743701760 INFO: CVideoPlayerVideo - Stillframe detected, switching to forced 25.000000 fps
22:16:39 T:140625743701760 DEBUG: CPullupCorrection: pattern lost on diff 200000.000000, number of losses 1
22:16:39 T:140625743701760 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 1
22:16:39 T:140625743701760 DEBUG: CVideoPlayerVideo::CalcDropRequirement - dropped in decoder, Sleeptime: -0.004835, Bufferlevel: 1, Gain: 0.080000
22:16:39 T:140625743701760 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 1
22:16:39 T:140625097488128 DEBUG: Previous line repeats 5 times.
22:16:39 T:140625097488128 WARNING: COutput::StateMachine - signal: 3 form port: timer not handled for state: 2
22:16:44 T:140625743701760 WARNING: Previous line repeats 2 times.
22:16:44 T:140625743701760 DEBUG: CPullupCorrection: detected pattern of length 1: 40000.00, frameduration: 40000.000000
22:16:49 T:140625097488128 WARNING: COutput::StateMachine - signal: 3 form port: timer not handled for state: 2
22:17:01 T:140626595108608 WARNING: Previous line repeats 3 times.
22:17:01 T:140626595108608 ERROR: Read - Error( -1, 22, Invalid argument ) - Retrying
22:17:01 T:140626595108608 ERROR: Read - Error( -1, 22, Invalid argument )
22:17:01 T:140626595108608 DEBUG: ffmpeg[7FE62E3F5700]: [mpegts] PES packet size mismatch
22:17:01 T:140626595108608 DEBUG: CVideoPlayer::SetCaching - caching state 1
22:17:01 T:140625743701760 INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback
22:17:01 T:140625743701760 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
22:17:01 T:140626595108608 ERROR: Read - Error( -1, 22, Invalid argument ) - Retrying
22:17:01 T:140625725617920 DEBUG: CDVDAudio::Pause - pausing audio stream
22:17:01 T:140626595108608 ERROR: Read - Error( -1, 22, Invalid argument )
22:17:01 T:140626595108608 DEBUG: ffmpeg[7FE62E3F5700]: [mpegts] PES packet size mismatch
22:17:01 T:140626595108608 NOTICE: CDVDMessageQueue::GetLevel() - can't determine level
22:17:01 T:140626595108608 NOTICE: Previous line repeats 2 times.
22:17:01 T:140626595108608 ERROR: Read - Error( -1, 22, Invalid argument ) - Retrying
22:17:01 T:140626595108608 ERROR: Read - Error( -1, 22, Invalid argument )
22:17:01 T:140626595108608 DEBUG: CVideoPlayer::SetCaching - caching state 0
22:17:01 T:140625725617920 DEBUG: CDVDAudio::Resume - resume audio stream
22:17:01 T:140625725617920 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_EOF
22:17:01 T:140625743701760 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
22:17:01 T:140625743701760 DEBUG: ffmpeg[7FE5FB7FE700]: [h264] Found reference and non-reference fields in the same frame, which is not implemented. Update your FFmpeg version to the newest one from Git. If the problem still occurs, it means that your file has a feature which has not been implemented.
22:17:01 T:140625743701760 DEBUG: ffmpeg[7FE5FB7FE700]: [h264] If you want to help, upload a sample of this file to ftp://upload.ffmpeg.org/incoming/ and contact the ffmpeg-devel mailing list. ([email protected])
22:17:01 T:140625743701760 ERROR: ffmpeg[7FE5FB7FE700]: [h264] decode_slice_header error
22:17:01 T:140626595108608 ERROR: Read - Error( -1, 22, Invalid argument ) - Retrying
22:17:01 T:140626595108608 ERROR: Read - Error( -1, 22, Invalid argument )
22:17:01 T:140626595108608 INFO: Process - eof reading from demuxer
22:17:01 T:140626595108608 NOTICE: CVideoPlayer::OnExit()
22:17:01 T:140626595108608 NOTICE: VideoPlayer: eof, waiting for queues to empty
22:17:01 T:140626595108608 NOTICE: Closing stream player 1
22:17:01 T:140626595108608 NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
22:17:01 T:140625725617920 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
22:17:01 T:140626595108608 NOTICE: Waiting for audio thread to exit
22:17:01 T:140625725617920 ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
22:17:01 T:140625725617920 NOTICE: thread end: CVideoPlayerAudio::OnExit()
22:17:01 T:140625725617920 DEBUG: Thread VideoPlayerAudio 140625725617920 terminating
22:17:01 T:140626595108608 NOTICE: Closing audio device
22:17:01 T:140627682248448 DEBUG: ActiveAE - start sync of audio stream
22:17:01 T:140627682248448 DEBUG: CActiveAE::DiscardStream - audio stream deleted
22:17:01 T:140627682248448 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
22:17:01 T:140626595108608 NOTICE: Deleting audio codec
22:17:01 T:140627682248448 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
22:17:01 T:140626595108608 NOTICE: Closing stream player 2
22:17:01 T:140626595108608 NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
22:17:01 T:140625743701760 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
22:17:01 T:140626595108608 NOTICE: waiting for video thread to exit
22:17:01 T:140625743701760 ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
22:17:01 T:140625743701760 NOTICE: thread end: video_thread
22:17:01 T:140626595108608 NOTICE: deleting video codec
22:17:01 T:140625743701760 DEBUG: Thread VideoPlayerVideo 140625743701760 terminating
22:17:01 T:140626595108608 DEBUG: VAAPI::Release pre-cleanup
22:17:01 T:140625029535488 DEBUG: ffmpeg[7FE5D0EE9700]: [src] w:1920 h:1080 pixfmt:nv12 tb:1/1 fr:0/1 sar:1/1 sws_param:
22:17:01 T:140625029535488 DEBUG: CFFmpegPostproc::Init - skip deinterlacing
22:17:01 T:140626595108608 DEBUG: CSMBFile::Close closing fd 10000
22:17:01 T:140626595108608 DEBUG: OnPlayBackEnded: play state was 2, starting 0
22:17:01 T:140626595108608 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
22:17:01 T:140626595108608 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
22:17:01 T:140626595108608 DEBUG: Thread VideoPlayer 140626595108608 terminating
22:17:01 T:140627692804160 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
22:17:01 T:140627692804160 DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
22:17:01 T:140627692804160 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
22:17:01 T:140627692804160 DEBUG: ------ Window Init (MyVideoNav.xml) ------
22:17:01 T:140627692804160 DEBUG: CGUIMediaWindow::GetDirectory (smb://MAC-MINI/Tennis/)
22:17:01 T:140627692804160 DEBUG: ParentPath = [smb://MAC-MINI/Tennis/]
22:17:01 T:140627673855744 INFO: CActiveAESink::OpenSink - initialize sink
22:17:01 T:140627673855744 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=PCH,DEV=2
22:17:01 T:140627673855744 INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=PCH,DEV=2"
22:17:01 T:140627673855744 INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=PCH,DEV=2,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00"
22:17:01 T:140627673855744 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
22:17:01 T:140627673855744 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
22:17:01 T:140627673855744 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2048, bufferSize 8192
22:17:01 T:140627673855744 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2048, bufferSize 8192
22:17:01 T:140627673855744 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 186 ms
22:17:01 T:140627673855744 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2
22:17:01 T:140627673855744 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR
22:17:01 T:140627673855744 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR (ALSA: FL FR)
22:17:01 T:140627673855744 DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
22:17:01 T:140627673855744 DEBUG: Output Device : HDA Intel PCH
22:17:01 T:140627673855744 DEBUG: Sample Rate : 44100
22:17:01 T:140627673855744 DEBUG: Sample Format : AE_FMT_S32NE
22:17:01 T:140627673855744 DEBUG: Channel Count : 2
22:17:01 T:140627673855744 DEBUG: Channel Layout: FL,FR
22:17:01 T:140627673855744 DEBUG: Frames : 2048
22:17:01 T:140627673855744 DEBUG: Frame Size : 8
22:17:01 T:140627682248448 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
22:17:01 T:140627692804160 DEBUG: Previous line repeats 1 times.
22:17:01 T:140627692804160 DEBUG: RunQuery took 1 ms for 0 items query: select * from movie_view WHERE c23=1
22:17:01 T:140627692804160 DEBUG: RunQuery took 0 ms for 1 items query: SELECT files.strFilename, files.playCount, bookmark.timeInSeconds, bookmark.totalTimeInSeconds FROM files LEFT JOIN bookmark ON files.idFile = bookmark.idFile AND bookmark.type = 1 WHERE files.idPath=1
22:17:01 T:140626595108608 DEBUG: Thread BackgroundLoader start, auto delete: false
22:17:01 T:140627692804160 INFO: ffmpeg[7FE66FACD840]: [mjpeg] Changeing bps to 8
22:17:01 T:140626595108608 DEBUG: Thread BackgroundLoader 140626595108608 terminating
22:17:01 T:140627692804160 NOTICE: CVideoPlayer::CloseFile()
22:17:01 T:140627692804160 NOTICE: VideoPlayer: waiting for threads to exit
22:17:01 T:140627692804160 NOTICE: VideoPlayer: finished waiting
22:17:01 T:140627692804160 DEBUG: DeleteRenderer - deleting renderer
22:17:01 T:140627692804160 DEBUG: LinuxRendererGL: Cleaning up GL resources
22:17:01 T:140627692804160 NOTICE: CVideoPlayer::CloseFile()
22:17:01 T:140627692804160 NOTICE: VideoPlayer: waiting for threads to exit
22:17:01 T:140627692804160 NOTICE: VideoPlayer: finished waiting
22:17:01 T:140627692804160 DEBUG: DeleteRenderer - deleting renderer
22:17:01 T:140627692804160 DEBUG: Radio UECP (RDS) Processor - delete ~CDVDRadioRDSData
22:17:01 T:140626595108608 DEBUG: Thread JobWorker start, auto delete: true
22:17:01 T:140626595108608 DEBUG: DoWork - Saving file state for video item smb://MAC-MINI/Tennis/WTA.2016.Australian.Open.Final.S.Williams.vs.Kerber.1080i.ESHD.ENG.ts
22:17:01 T:140626595108608 DEBUG: DoWork - Marking video item smb://MAC-MINI/Tennis/WTA.2016.Australian.Open.Final.S.Williams.vs.Kerber.1080i.ESHD.ENG.ts as watched
22:17:01 T:140625534494464 WARNING: COutput::StateMachine - signal: 3 form port: timer not handled for state: 2Reproduced with OpenELEC-Generic.x86_64-7.0-devel-20160129204252-r21994-g8628410.
