Stream Timeout, Unknown Problem... and Recorded TV share blocked

  Thread Rating:
  • 0 Vote(s) - 0 Average
  • 1
  • 2
  • 3
  • 4
  • 5
Post Reply
_WiLloW_ Offline
Junior Member
Posts: 7
Joined: Jun 2015
Reputation: 0
Bug  Stream Timeout, Unknown Problem... and Recorded TV share blocked
Post: #1
Hello,

Since last two weeks I'm getting this error in Kodi while watching LiveTV: "Stream Timeout, Unknown Problem". Kodi suddenly freezes for 30 to 60 seconds and shows that message. Also, "Recorded TV" share in the server gets blocked for the same time.

There are 350GB available for recordings and ServerWMC temp files, nothing changed in Windows or ServerWMC config. The HDD has no cooling, space or sanity problems. No high CPU use or RAM issues. The only change: Kodi was updated to Krypton in two of three clients.

ServerWMC log:

Code:
2017/02/28 12:09:10.464 Finished request GetRecordings in 0,00s
2017/02/28 12:09:15.913 StreamFileSize> client Kodi^loli-pc, count: 5, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:18.950 StreamFileSize> client Kodi^loli-pc, count: 10, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:21.979 StreamFileSize> client Kodi^loli-pc, count: 15, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:25.033 StreamFileSize> client Kodi^loli-pc, count: 20, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:28.062 StreamFileSize> client Kodi^loli-pc, count: 25, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:31.091 StreamFileSize> client Kodi^loli-pc, count: 30, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:34.137 StreamFileSize> client Kodi^loli-pc, count: 35, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:37.170 StreamFileSize> client Kodi^loli-pc, count: 40, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:40.197 StreamFileSize> client Kodi^loli-pc, count: 45, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:43.256 StreamFileSize> client Kodi^loli-pc, count: 50, ts stream size: 92.274.688 (wtv: 522.977.280)
2017/02/28 12:09:53.935 Received client request: loli-pc|192.168.1.4|CloseLiveStream
2017/02/28 12:09:53.935 CloseStream> -----------------start------------------------
2017/02/28 12:09:53.935 Remux::Stop> stop remux requested
2017/02/28 12:09:56.713 CloseRemux> warning: remux job did not end smoothly
2017/02/28 12:09:56.713 LiveRemuxStream::Close> remux stopped successfully
2017/02/28 12:09:56.713 RecordToWTV::Close> isPassive is False => COM recorder will be stopped
2017/02/28 12:10:13.192 Parse> Exception: Subproceso anulado.
2017/02/28 12:10:13.192 Parse>   Pass Type: Remux
2017/02/28 12:10:13.192 Parse>   Guid count: 131.208  (Min:500 - Max:2.000)
2017/02/28 12:10:13.192 Parse>   Header:
2017/02/28 12:10:13.192 Parse>   re-throwing exception
2017/02/28 12:10:13.192 Remux> error: System.Threading.ThreadAbortException: Subproceso anulado.
   en Remuxer.demux.microsoft.WtvToPesDemuxer.parse(JobStreamI jobStm, MuxManager muxManager)
   en Remuxer.muxer.MuxManager.mux(JobStreamI stream)
   en Remuxer.Remux.Start(String clientName, String outFullFileName)
2017/02/28 12:10:13.192 WriteChunk> long interval between writes (ms): 61014
2017/02/28 12:10:13.342 Remux> requesting D:\Recorded TV\TempSWMC\LiveTV_Kodi^loli-pc_DVB-T_6_2017_02_28_12_05_53.wtv be saved from deletion
2017/02/28 12:10:13.342 Remux> ENDED, >>>>>>>>>> Run Time: 4,25 min <<<<<<<<<<
2017/02/28 12:10:13.752 LiveRemuxStream::Close> wtv closed successfully
2017/02/28 12:10:13.814 LiveRemuxStream::Close> wtv file size: 117.964.800 (0x7080000)
2017/02/28 12:10:13.814 LiveRemuxStream::Close> WTV FILE SAVED FOR DEBUG: D:\Recorded TV\TempSWMC\LiveTV_Kodi^loli-pc_DVB-T_6_2017_02_28_12_05_53.wtv
2017/02/28 12:10:13.814 LiveRemuxStream::Close> closed in 19,88 sec
2017/02/28 12:10:13.814 Close> closed stream for client: Kodi^loli-pc
2017/02/28 12:10:13.814 CloseStream> -----------------done-------------------------
2017/02/28 12:10:13.814 Finished request CloseLiveStream in 19,89s

ServerWMC config:

Code:
2017/02/28 10:48:09.062 -----------------------------------------
2017/02/28 10:48:09.077 Non-default Config Settings -------------
2017/02/28 10:48:09.077 isAutoStart: True >>Default: False
2017/02/28 10:48:09.077 StartupMinimized: True >>Default: False
2017/02/28 10:48:09.077 IsCloseToSysTray: True >>Default: False
2017/02/28 10:48:09.077 UseCredentialsInNetworkPath: True >>Default: False
2017/02/28 10:48:09.077 useEpisodeInTitleString: True >>Default: False
2017/02/28 10:48:09.093 ChannelDisplayFormatString: {1} >>Default: {1}/{0}
2017/02/28 10:48:09.093 RecMoviesDirName: Peliculas >>Default: Movies
2017/02/28 10:48:09.093 CurrentRecordDirName: * Grabando >>Default: * Recording now
2017/02/28 10:48:09.093 GroupRecSports: True >>Default: False
2017/02/28 10:48:09.093 RecSportsDirName: Deportes >>Default: Sports
2017/02/28 10:48:09.093 HideEncryptedChannel: True >>Default: False
2017/02/28 10:48:09.093 ForcedRadioChannels: 95,96,97,98,99,100,101,102,103,104,105,106,107,108,109,110 >>Default:
2017/02/28 10:48:09.093 NoGuideDataAvailableStr: No hay EPG >>Default: No guide data available
2017/02/28 10:48:09.093 --- ForcedRadioChannelRanges:
2017/02/28 10:48:09.093   Min: 95  Max: 95
2017/02/28 10:48:09.093   Min: 96  Max: 96
2017/02/28 10:48:09.093   Min: 97  Max: 97
2017/02/28 10:48:09.093   Min: 98  Max: 98
2017/02/28 10:48:09.093   Min: 99  Max: 99
2017/02/28 10:48:09.093   Min: 100  Max: 100
2017/02/28 10:48:09.093   Min: 101  Max: 101
2017/02/28 10:48:09.093   Min: 102  Max: 102
2017/02/28 10:48:09.093   Min: 103  Max: 103
2017/02/28 10:48:09.093   Min: 104  Max: 104
2017/02/28 10:48:09.093   Min: 105  Max: 105
2017/02/28 10:48:09.093   Min: 106  Max: 106
2017/02/28 10:48:09.093   Min: 107  Max: 107
2017/02/28 10:48:09.093   Min: 108  Max: 108
2017/02/28 10:48:09.093   Min: 109  Max: 109
2017/02/28 10:48:09.093   Min: 110  Max: 110
2017/02/28 10:48:09.093 -----------------------------------------
(I just notice forced radio channels setting is a range Tongue)

Client Kodi.log:

Code:
11:47:39 T:140658123712256 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
11:47:41 T:140658132104960 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
11:48:14 T:140658590328576  NOTICE: CDVDPlayer::OnExit()
11:48:14 T:140658590328576  NOTICE: DVDPlayer: eof, waiting for queues to empty
11:48:14 T:140658590328576  NOTICE: Closing stream player 1
11:48:14 T:140658590328576  NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
11:48:14 T:140658590328576  NOTICE: Waiting for audio thread to exit
11:48:14 T:140658123712256  NOTICE: thread end: CDVDPlayerAudio::OnExit()
11:48:14 T:140658590328576  NOTICE: Closing audio device
11:48:14 T:140658132104960 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
11:48:14 T:140658590328576  NOTICE: Deleting audio codec
11:48:14 T:140658590328576  NOTICE: Closing stream player 2
11:48:14 T:140658590328576  NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
11:48:14 T:140658590328576  NOTICE: waiting for video thread to exit
11:48:14 T:140658132104960   ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
11:48:14 T:140658132104960  NOTICE: thread end: video_thread
11:48:14 T:140658590328576  NOTICE: deleting video codec
11:48:14 T:140660236633856  NOTICE: PulseAudio: Opened device Default in pcm mode with Buffersize 150 ms
11:48:22 T:140660683360256  NOTICE: CDVDPlayer::CloseFile()
11:48:22 T:140660683360256  NOTICE: DVDPlayer: waiting for threads to exit
11:48:22 T:140660683360256  NOTICE: DVDPlayer: finished waiting
11:48:22 T:140660683360256  NOTICE: CDVDPlayer::CloseFile()
11:48:22 T:140660683360256  NOTICE: DVDPlayer: waiting for threads to exit
11:48:22 T:140660683360256  NOTICE: DVDPlayer: finished waiting
11:49:55 T:140660683360256  NOTICE: Samba is idle. Closing the remaining connections

As I said, Recorded TV share in the server gets blocked for about 30 to 60 seconds, at the same time that the clients freezes (not all Kodi, UI responds, but Kodi also freezes if I try to pause, stop, rew, ff... or any other interaction with LiveTV stream until Recorded TV share blocking ends)

More than 3 years using ServerWMC without problems... Thank you guys.

Could you help me, please?
find quote
krustyreturns Offline
Moderator
Posts: 3,028
Joined: Aug 2012
Reputation: 77
Location: Springfield Heights, CA
Post: #2
i think you are right that the problem is due to the recorded tv folder getting 'blocked', because the log indicates that the stream data has stopped growing - like maybe the disk can no longer be written to. i don't know why it is happening though. how are you determining that the rec tv share is getting blocked?

Windows Media Center PVR addon (pvr.wmc) and server backend (ServerWMC)
http://bit.ly/serverwmc
find quote
_WiLloW_ Offline
Junior Member
Posts: 7
Joined: Jun 2015
Reputation: 0
Post: #3
(2017-03-01 00:28)krustyreturns Wrote:  i think you are right that the problem is due to the recorded tv folder getting 'blocked', because the log indicates that the stream data has stopped growing - like maybe the disk can no longer be written to. i don't know why it is happening though. how are you determining that the rec tv share is getting blocked?
I tried to access Recorded TV share at the same time... and I can't: the linux client connects, it tries to load the content but keeps waiting. Just when the stream is fully stopped the share contents are loaded.

This is the problem: suddenly, something eats the HDD (100% use). When this happens all clients stream freeze for 30 to 60 seconds. A few seconds after the freeze happens, the "Stream Timeout. Unknown Problem" message is shown. When the HDD activity descend to normal values (10% to 20% use) the stream is stopped and the share is accessible again.

[Image: 11c4cah.jpg]

When the HDD activity is 100%, the disk I/O is 0MB/s and all client streams die.

I don't know what the hell is happening... any idea?

Thank you.
find quote
krustyreturns Offline
Moderator
Posts: 3,028
Joined: Aug 2012
Reputation: 77
Location: Springfield Heights, CA
Post: #4
i can't think of anything. i am interested in whether this is really a problem with the new kodi, so if you can't find anything else to try, you might try seeing if reverting solves the problem.

Windows Media Center PVR addon (pvr.wmc) and server backend (ServerWMC)
http://bit.ly/serverwmc
find quote
_WiLloW_ Offline
Junior Member
Posts: 7
Joined: Jun 2015
Reputation: 0
Post: #5
(2017-03-01 18:13)krustyreturns Wrote:  i can't think of anything. i am interested in whether this is really a problem with the new kodi, so if you can't find anything else to try, you might try seeing if reverting solves the problem.
No, no... problems started before I upgraded ServerWMC to the latest version. This is not a ServerWMC related problem. I'm now seeing the same behaviour in the SSD (100% use totally random for around 30 seconds, no I/O, etc).

This is a Windows problem. Another one... and I'm tired. The only reason to maintain Windows is the graphics driver video filters, mainly sharpness, in Linux is not available for Intel IGP's. But I think it's time to switch.

Anyway... thank you!
find quote