2019-01-12, 23:59
Have been a faithful user and contributor - running without issues for months.
Not sure why am having problems without changing anything (at least that I'm aware of).
No clients (all Raspberry Pis) can play any live or recorded shows. They all can still connect to the WMC server, see the lists of recordings, channel guide etc.
When I try to play a live or recorded show, it times out after a few seconds.
I expect somehow permissions got changed (not sure how? Maybe a windows auto update?) and kodi can no longer access the recorded show directory on the WMC server
I recently removed Malwarebytes as it was preventing the clients from seeing the server at all after an update - not sure if that's relevant. verified Windows firewall is turned off
Have tried changing server name to IP, no luck.
How can I debug this??
relevant section of the log file when tryting to play a live stream (there is no entries when I try and play a recorded show):
2019/01/12 16:19:14.896 OpenLiveStream> -----------------start------------------------
2019/01/12 16:19:14.911 OpenLiveStream> client: Kodi^FRoom requesting live stream on channel CNN/100
2019/01/12 16:19:14.942 LiveRemuxStream> live-tv started
2019/01/12 16:19:15.020 SetChannel> Channel: 100 : CNN - E1C8 = { (100 : CNN - 6C1B) + [ 100 : CNN - C8DE, 1541 : CNN - F7202FE, 1541 : CNN - F720427] }
2019/01/12 16:19:15.020 SetChannel> Tuners available for this channel: 12
2019/01/12 16:19:15.020 SetChannel> Tuner DecoyMethod: OnDemand
2019/01/12 16:19:15.020 SetChannel> ---
2019/01/12 16:19:15.020 SetChannel> Attempt: 0, Tuner: HDHomeRun Prime Tuner 131B9F10-2 / 2d633089-14e1-41b4-84ff-53d62bb98022
2019/01/12 16:19:15.020 SetChannel> > Encrypted: False
2019/01/12 16:19:15.020 SetChannel> > RecorderInfo found: True
2019/01/12 16:19:15.020 SetChannel> > Recorder Content Protection: PROT_COPY_FREE
2019/01/12 16:19:15.161 SetChannel> > Status: Available, client:
2019/01/12 16:19:15.161 SetChannel> *** requested number of available tuners found, stopping search ***
2019/01/12 16:19:15.161 SetChannel> ---
2019/01/12 16:19:15.161 SetChannel> available tuners found: 1 [decoys:0], requested: 1, searched: 1
2019/01/12 16:19:15.176 SetChannel> Tuner: HDHomeRun Prime Tuner 131B9F10-2 will be used for the live stream
2019/01/12 16:19:17.563 SetChannel> Recorder acquired: True
2019/01/12 16:19:17.594 SetChannel> TuneRequest set
2019/01/12 16:19:17.688 LiveRemuxStream> wtv recording started in 2.75 sec
2019/01/12 16:19:17.688 LiveRemuxStream> stream output file: LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts
2019/01/12 16:19:17.688 LiveRemuxStream> started remux thread: 'CNN-100:57800'
2019/01/12 16:19:17.797 Remux::ctor> input settings:
2019/01/12 16:19:17.797 > Search packet data for detailed stream info on all streams: False
2019/01/12 16:19:17.797 > Process only audio streams: False
2019/01/12 16:19:17.797 > Drop all video streams from output if found: False
2019/01/12 16:19:17.813 Remux::Start> Starting descriptor scan...
2019/01/12 16:19:17.860 Remux::FindDescriptors> Forcing detailed stream info analysis: False
2019/01/12 16:19:17.860 Remux::FindDescriptors> Scanning wtv for streams...
2019/01/12 16:19:19.704 Parse> Guid: 0 took 1.70 sec, it was attempted 123 times
2019/01/12 16:19:19.764 Parse> Next 4 Guids: 0.06 sec, 0.00 sec, 0.00 sec, 0.00 sec,
2019/01/12 16:19:19.774 Parse> Language 'eng' for stream Id 10
2019/01/12 16:19:19.774 Parse> Language 'spa' for stream Id 11
2019/01/12 16:19:19.794 WaitUntilTrueOrTimeout> remux data found
2019/01/12 16:19:20.644 Parse> Total Descriptor parse time: 2.64 sec
2019/01/12 16:19:20.644 Pass Type: 'Descriptor':
2019/01/12 16:19:20.644 > WtvToPesDemuxer:
arse> total guid headers processed: 500 (Min:500 - Max:2,000)
2019/01/12 16:19:20.644 > WtvToPesDemuxer:arse> total data packets processed: 97
2019/01/12 16:19:20.674 Remux::FindDescriptors> wtv scanned (2.81 sec), Streams found:
2019/01/12 16:19:20.674 > Audio: ID:10 (eng) ac3
2019/01/12 16:19:20.674 > Audio: ID:11 (spa) ac3
2019/01/12 16:19:20.684 > Video: ID:12 mpeg2video MP-ML 720x480i fps: 30000/1001 AR: 4:3 (PTS_not_mono)
2019/01/12 16:19:20.684 Remux::FindDescriptors> ended successfully.
2019/01/12 16:19:20.694 GetLinearStream> Stream used: ID:10 (eng) ac3
2019/01/12 16:19:20.704 Remux::Start> Starting data remux...
2019/01/12 16:19:20.734 WriteChunk> first output file write occurred
2019/01/12 16:19:20.744 LiveRemuxStream> 'ts' file created, size: 163,840 in 3.06 sec
2019/01/12 16:19:20.744 LiveRemuxStream> total time: 5.80 sec
2019/01/12 16:19:20.754 OpenLiveStream> stream path returned to client: smb://xbmc:****@192.168.1.11/Recorded TV/TempSWMC/LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts
2019/01/12 16:19:20.754 OpenLiveStream> -----------------done-------------------------
2019/01/12 16:19:20.804 Finished request OpenLiveStream in 5.94s
2019/01/12 16:19:20.864 Received client request: FRoom|192.168.1.16|StreamStartError|smb://xbmc:****@192.168.1.11/Recorded TV/TempSWMC/LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts
2019/01/12 16:19:20.864 StreamStartError> client 'Kodi^FRoom' reports error opening stream, will close stream down
2019/01/12 16:19:20.864 StreamStartError> client 'Kodi^FRoom' path to stream file: 'smb://xbmc:****@192.168.1.11/Recorded TV/TempSWMC/LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts'
2019/01/12 16:19:20.864 StreamStartError> client 'Kodi^FRoom' calling CloseStream
2019/01/12 16:19:20.874 Remux::Stop> stop remux requested
2019/01/12 16:19:20.884 WtvToPesDemuxer:arse> Guid header detects stream end
2019/01/12 16:19:20.884 Pass Type: 'Remux':
2019/01/12 16:19:20.884 > WtvToPesDemuxer:arse> total guid headers processed: 609
2019/01/12 16:19:20.884 > WtvToPesDemuxer:arse> total data packets processed: 120
2019/01/12 16:19:20.884 Remux> ENDED, >>>>>>>>>> Run Time: 0.00 min <<<<<<<<<<
2019/01/12 16:19:20.894 LiveRemuxStream::Close> remux stopped successfully
2019/01/12 16:19:20.954 DeleteTS> ts file size: 557,056
2019/01/12 16:19:22.194 LiveRemuxStream::Close> ts file deleted: E:\Recorded TV\TempSWMC\LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts
2019/01/12 16:19:22.194 RecordToWTV::Close> isPassive is False => COM recorder will be stopped
2019/01/12 16:19:22.437 LiveRemuxStream::Close> wtv closed successfully
2019/01/12 16:19:22.500 LiveRemuxStream::Close> wtv file size: 1,835,008 (0x1C0000)
2019/01/12 16:19:22.500 LiveRemuxStream::Close> wtv file deleted: E:\Recorded TV\TempSWMC\LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.wtv
2019/01/12 16:19:22.500 LiveRemuxStream::Close> closed in 1.63 sec
2019/01/12 16:19:22.500 Close> closed stream for client: Kodi^FRoom
2019/01/12 16:19:22.500 Finished request StreamStartError in 1.64s
2019/01/12 16:19:33.607 Received client request: FRoom|192.168.1.16|GetResumePosition|10977524412904951
2019/01/12 16:19:33.607 Finished request GetResumePosition in 0.00s
2019/01/12 16:20:09.908 Received client request: Theater|192.168.1.21|GetSeriesTimers
Not sure why am having problems without changing anything (at least that I'm aware of).
No clients (all Raspberry Pis) can play any live or recorded shows. They all can still connect to the WMC server, see the lists of recordings, channel guide etc.
When I try to play a live or recorded show, it times out after a few seconds.
I expect somehow permissions got changed (not sure how? Maybe a windows auto update?) and kodi can no longer access the recorded show directory on the WMC server
I recently removed Malwarebytes as it was preventing the clients from seeing the server at all after an update - not sure if that's relevant. verified Windows firewall is turned off
Have tried changing server name to IP, no luck.
How can I debug this??
relevant section of the log file when tryting to play a live stream (there is no entries when I try and play a recorded show):
2019/01/12 16:19:14.896 OpenLiveStream> -----------------start------------------------
2019/01/12 16:19:14.911 OpenLiveStream> client: Kodi^FRoom requesting live stream on channel CNN/100
2019/01/12 16:19:14.942 LiveRemuxStream> live-tv started
2019/01/12 16:19:15.020 SetChannel> Channel: 100 : CNN - E1C8 = { (100 : CNN - 6C1B) + [ 100 : CNN - C8DE, 1541 : CNN - F7202FE, 1541 : CNN - F720427] }
2019/01/12 16:19:15.020 SetChannel> Tuners available for this channel: 12
2019/01/12 16:19:15.020 SetChannel> Tuner DecoyMethod: OnDemand
2019/01/12 16:19:15.020 SetChannel> ---
2019/01/12 16:19:15.020 SetChannel> Attempt: 0, Tuner: HDHomeRun Prime Tuner 131B9F10-2 / 2d633089-14e1-41b4-84ff-53d62bb98022
2019/01/12 16:19:15.020 SetChannel> > Encrypted: False
2019/01/12 16:19:15.020 SetChannel> > RecorderInfo found: True
2019/01/12 16:19:15.020 SetChannel> > Recorder Content Protection: PROT_COPY_FREE
2019/01/12 16:19:15.161 SetChannel> > Status: Available, client:
2019/01/12 16:19:15.161 SetChannel> *** requested number of available tuners found, stopping search ***
2019/01/12 16:19:15.161 SetChannel> ---
2019/01/12 16:19:15.161 SetChannel> available tuners found: 1 [decoys:0], requested: 1, searched: 1
2019/01/12 16:19:15.176 SetChannel> Tuner: HDHomeRun Prime Tuner 131B9F10-2 will be used for the live stream
2019/01/12 16:19:17.563 SetChannel> Recorder acquired: True
2019/01/12 16:19:17.594 SetChannel> TuneRequest set
2019/01/12 16:19:17.688 LiveRemuxStream> wtv recording started in 2.75 sec
2019/01/12 16:19:17.688 LiveRemuxStream> stream output file: LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts
2019/01/12 16:19:17.688 LiveRemuxStream> started remux thread: 'CNN-100:57800'
2019/01/12 16:19:17.797 Remux::ctor> input settings:
2019/01/12 16:19:17.797 > Search packet data for detailed stream info on all streams: False
2019/01/12 16:19:17.797 > Process only audio streams: False
2019/01/12 16:19:17.797 > Drop all video streams from output if found: False
2019/01/12 16:19:17.813 Remux::Start> Starting descriptor scan...
2019/01/12 16:19:17.860 Remux::FindDescriptors> Forcing detailed stream info analysis: False
2019/01/12 16:19:17.860 Remux::FindDescriptors> Scanning wtv for streams...
2019/01/12 16:19:19.704 Parse> Guid: 0 took 1.70 sec, it was attempted 123 times
2019/01/12 16:19:19.764 Parse> Next 4 Guids: 0.06 sec, 0.00 sec, 0.00 sec, 0.00 sec,
2019/01/12 16:19:19.774 Parse> Language 'eng' for stream Id 10
2019/01/12 16:19:19.774 Parse> Language 'spa' for stream Id 11
2019/01/12 16:19:19.794 WaitUntilTrueOrTimeout> remux data found
2019/01/12 16:19:20.644 Parse> Total Descriptor parse time: 2.64 sec
2019/01/12 16:19:20.644 Pass Type: 'Descriptor':
2019/01/12 16:19:20.644 > WtvToPesDemuxer:
arse> total guid headers processed: 500 (Min:500 - Max:2,000)2019/01/12 16:19:20.644 > WtvToPesDemuxer:
arse> total data packets processed: 972019/01/12 16:19:20.674 Remux::FindDescriptors> wtv scanned (2.81 sec), Streams found:
2019/01/12 16:19:20.674 > Audio: ID:10 (eng) ac3
2019/01/12 16:19:20.674 > Audio: ID:11 (spa) ac3
2019/01/12 16:19:20.684 > Video: ID:12 mpeg2video MP-ML 720x480i fps: 30000/1001 AR: 4:3 (PTS_not_mono)
2019/01/12 16:19:20.684 Remux::FindDescriptors> ended successfully.
2019/01/12 16:19:20.694 GetLinearStream> Stream used: ID:10 (eng) ac3
2019/01/12 16:19:20.704 Remux::Start> Starting data remux...
2019/01/12 16:19:20.734 WriteChunk> first output file write occurred
2019/01/12 16:19:20.744 LiveRemuxStream> 'ts' file created, size: 163,840 in 3.06 sec
2019/01/12 16:19:20.744 LiveRemuxStream> total time: 5.80 sec
2019/01/12 16:19:20.754 OpenLiveStream> stream path returned to client: smb://xbmc:****@192.168.1.11/Recorded TV/TempSWMC/LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts
2019/01/12 16:19:20.754 OpenLiveStream> -----------------done-------------------------
2019/01/12 16:19:20.804 Finished request OpenLiveStream in 5.94s
2019/01/12 16:19:20.864 Received client request: FRoom|192.168.1.16|StreamStartError|smb://xbmc:****@192.168.1.11/Recorded TV/TempSWMC/LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts
2019/01/12 16:19:20.864 StreamStartError> client 'Kodi^FRoom' reports error opening stream, will close stream down
2019/01/12 16:19:20.864 StreamStartError> client 'Kodi^FRoom' path to stream file: 'smb://xbmc:****@192.168.1.11/Recorded TV/TempSWMC/LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts'
2019/01/12 16:19:20.864 StreamStartError> client 'Kodi^FRoom' calling CloseStream
2019/01/12 16:19:20.874 Remux::Stop> stop remux requested
2019/01/12 16:19:20.884 WtvToPesDemuxer:
arse> Guid header detects stream end2019/01/12 16:19:20.884 Pass Type: 'Remux':
2019/01/12 16:19:20.884 > WtvToPesDemuxer:
arse> total guid headers processed: 6092019/01/12 16:19:20.884 > WtvToPesDemuxer:
arse> total data packets processed: 1202019/01/12 16:19:20.884 Remux> ENDED, >>>>>>>>>> Run Time: 0.00 min <<<<<<<<<<
2019/01/12 16:19:20.894 LiveRemuxStream::Close> remux stopped successfully
2019/01/12 16:19:20.954 DeleteTS> ts file size: 557,056
2019/01/12 16:19:22.194 LiveRemuxStream::Close> ts file deleted: E:\Recorded TV\TempSWMC\LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.ts
2019/01/12 16:19:22.194 RecordToWTV::Close> isPassive is False => COM recorder will be stopped
2019/01/12 16:19:22.437 LiveRemuxStream::Close> wtv closed successfully
2019/01/12 16:19:22.500 LiveRemuxStream::Close> wtv file size: 1,835,008 (0x1C0000)
2019/01/12 16:19:22.500 LiveRemuxStream::Close> wtv file deleted: E:\Recorded TV\TempSWMC\LiveTV_Kodi^FRoom_Digital Cable_100_2019_01_12_16_19_14.wtv
2019/01/12 16:19:22.500 LiveRemuxStream::Close> closed in 1.63 sec
2019/01/12 16:19:22.500 Close> closed stream for client: Kodi^FRoom
2019/01/12 16:19:22.500 Finished request StreamStartError in 1.64s
2019/01/12 16:19:33.607 Received client request: FRoom|192.168.1.16|GetResumePosition|10977524412904951
2019/01/12 16:19:33.607 Finished request GetResumePosition in 0.00s
2019/01/12 16:20:09.908 Received client request: Theater|192.168.1.21|GetSeriesTimers
