2016-02-03, 18:05
Good Morning,
My HDHomeRun Prime device finally bit the dust during a storm after years of excellent use. I had some trouble getting Win 8.1 WMC to pick up the replacement device so I simply spun up a new Win 8.1 MCE machine in Hyper-V Host, just like I had with the previous build.
I have everything setup as I believe it should be. Kodi clients connect, pull down guide, channel icons, etc. but when they go to play a channel, it spins for a few seconds then stops. The HDHomeRun AddOn for Kodi works fine, so I recognize that it must be something in my ServerWMC configuration. Please find below the most recent log when attempting to open a channel. Any thoughts or guidance would be greatly appreciated.
2016/02/03 07:54:21.053 OpenLiveStream> -----------------start------------------------
2016/02/03 07:54:21.053 OpenLiveStream> client: Kodi^OpenELEC requesting live stream on channel CNNHD/788
2016/02/03 07:54:21.074 LiveRemuxStream> live-tv started
2016/02/03 07:54:21.114 SetChannel> Channel: 788 : CNNHD - DDF5 = { (788 : CNNHD - 6E50) + [ 788 : CNNHD - D6DF] }
2016/02/03 07:54:21.124 SetChannel> Tuners available for this channel: 3
2016/02/03 07:54:21.124 SetChannel> Tuner DecoyMethod: OnDemand
2016/02/03 07:54:21.124 SetChannel> ---
2016/02/03 07:54:21.124 SetChannel> Attempt: 0, Tuner: HDHomeRun Prime Tuner 1322A20B-0 / ac40a792-f305-4085-92ad-d18f1e844808
2016/02/03 07:54:21.124 SetChannel> > Encrypted: False
2016/02/03 07:54:21.134 SetChannel> > RecorderInfo found: True
2016/02/03 07:54:21.134 SetChannel> > Recorder Content Protection: PROT_COPY_FREE
2016/02/03 07:54:21.154 SetChannel> > Status: NOT Available, client: playback\recorderbroker&ehshell.exe&2456
2016/02/03 07:54:21.154 SetChannel> ---
2016/02/03 07:54:21.154 SetChannel> Attempt: 1, Tuner: HDHomeRun Prime Tuner 1322A20B-2 / b0051200-3508-41c6-be77-aa01896a1621
2016/02/03 07:54:21.154 SetChannel> > Encrypted: False
2016/02/03 07:54:21.164 SetChannel> > RecorderInfo found: True
2016/02/03 07:54:21.164 SetChannel> > Recorder Content Protection: PROT_COPY_FREE
2016/02/03 07:54:21.224 SetChannel> > Status: Available, client:
2016/02/03 07:54:21.224 SetChannel> *** requested number of available tuners found, stopping search ***
2016/02/03 07:54:21.224 SetChannel> ---
2016/02/03 07:54:21.224 SetChannel> available tuners found: 1 [decoys:0], requested: 1, searched: 2
2016/02/03 07:54:21.234 SetChannel> Tuner: HDHomeRun Prime Tuner 1322A20B-2 will be used for the live stream
2016/02/03 07:54:21.234 SetChannel> Recorder acquired: True
2016/02/03 07:54:21.234 SetChannel> TuneRequest set
2016/02/03 07:54:21.274 LiveRemuxStream> wtv recording started in 0.20 sec
2016/02/03 07:54:21.274 LiveRemuxStream> stream output file: LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts
2016/02/03 07:54:21.274 LiveRemuxStream> started remux thread: 'CNNHD-788:56821'
2016/02/03 07:54:21.355 Remux::Start> Starting descriptor scan...
2016/02/03 07:54:21.385 Remux::FindDescriptors> Scanning wtv for streams...
2016/02/03 07:54:23.545 Parse> Guid: 0 took 2.02 sec, it was attempted 199 times
2016/02/03 07:54:23.585 Parse> Next 4 Guids: 0.04 sec, 0.00 sec, 0.00 sec, 0.00 sec,
2016/02/03 07:54:23.766 Parse> Language 'eng' for stream Id 25
2016/02/03 07:54:23.796 WaitUntilTrueOrTimeout> remux data found
2016/02/03 07:54:24.801 Parse> Total Descriptor parse time: 3.27 sec
2016/02/03 07:54:24.801 Pass Type: 'Descriptor':
2016/02/03 07:54:24.801 > WtvToPesDemuxer:arse> total guid headers processed: 500 (Min:500 - Max:2,000)
2016/02/03 07:54:24.811 > WtvToPesDemuxer:arse> total data packets processed: 113
2016/02/03 07:54:24.811 Remux::FindDescriptors> wtv scanned (3.43 sec), Streams found:
2016/02/03 07:54:24.821 > Audio: ID:25 (eng) ac3 5.1 48000 Hz 448 kb/s
2016/02/03 07:54:24.821 > Video: ID:26 mpeg2video MP-HL 1920x1080i fps: 30000/1001 AR: 16:9
2016/02/03 07:54:24.821 > SubTitle: ID:27 ClosedCaption
2016/02/03 07:54:24.821 Remux::FindDescriptors> Output streams:
2016/02/03 07:54:24.821 > Audio: ID:25 (eng) ac3 5.1 48000 Hz 448 kb/s
2016/02/03 07:54:24.821 > Video: ID:26 mpeg2video MP-HL 1920x1080i fps: 30000/1001 AR: 16:9
2016/02/03 07:54:24.821 Remux::FindDescriptors> ended successfully.
2016/02/03 07:54:24.851 GetLinearStream> Stream used: ID:25 (eng) ac3 5.1 48000 Hz 448 kb/s
2016/02/03 07:54:24.881 Remux::Start> Starting data remux...
2016/02/03 07:54:24.961 WriteChunk> first output file write occurred
2016/02/03 07:54:25.001 LiveRemuxStream> 'ts' file created, size: 262,144 in 3.73 sec
2016/02/03 07:54:25.001 LiveRemuxStream> total time: 3.93 sec
2016/02/03 07:54:25.011 OpenLiveStream> stream path returned to client: smb://LIVETVSERVER/Users/Public/Recorded TV/TempSWMC/LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts
2016/02/03 07:54:25.011 OpenLiveStream> -----------------done-------------------------
2016/02/03 07:54:25.011 Finished request OpenLiveStream in 3.98s
2016/02/03 07:54:25.052 Received client request: OpenELEC|192.168.35.15|StreamStartError|smb://LIVETVSERVER/Users/Public/Recorded TV/TempSWMC/LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts
2016/02/03 07:54:25.052 StreamStartError> client 'Kodi^OpenELEC' reports error opening stream, will close stream down
2016/02/03 07:54:25.052 StreamStartError> client 'Kodi^OpenELEC' path to stream file: 'smb://LIVETVSERVER/Users/Public/Recorded TV/TempSWMC/LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts'
2016/02/03 07:54:25.052 StreamStartError> client 'Kodi^OpenELEC' calling CloseStream
2016/02/03 07:54:25.072 Remux::Stop> stop remux requested
2016/02/03 07:54:25.082 WtvToPesDemuxer:arse> Guid header detects stream end
2016/02/03 07:54:25.082 Pass Type: 'Remux':
2016/02/03 07:54:25.082 > WtvToPesDemuxer:arse> total guid headers processed: 540
2016/02/03 07:54:25.082 > WtvToPesDemuxer:arse> total data packets processed: 70
2016/02/03 07:54:25.092 Remux> ENDED, >>>>>>>>>> Run Time: 0.00 min <<<<<<<<<<
2016/02/03 07:54:25.102 LiveRemuxStream::Close> remux stopped successfully
2016/02/03 07:54:25.172 DeleteTS> ts file size: 1,310,720
2016/02/03 07:54:25.172 LiveRemuxStream::Close> ts file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts
2016/02/03 07:54:25.182 RecordToWTV::Close> isPassive is False => COM recorder will be stopped
2016/02/03 07:54:25.293 LiveRemuxStream::Close> wtv closed successfully
2016/02/03 07:54:25.353 LiveRemuxStream::Close> wtv file size: 2,097,152 (0x200000)
2016/02/03 07:54:25.353 LiveRemuxStream::Close> wtv file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.wtv
2016/02/03 07:54:25.353 LiveRemuxStream::Close> closed in 0.29 sec
2016/02/03 07:54:25.353 Close> closed stream for client: Kodi^OpenELEC
2016/02/03 07:54:25.353 Finished request StreamStartError in 0.30s
My HDHomeRun Prime device finally bit the dust during a storm after years of excellent use. I had some trouble getting Win 8.1 WMC to pick up the replacement device so I simply spun up a new Win 8.1 MCE machine in Hyper-V Host, just like I had with the previous build.
I have everything setup as I believe it should be. Kodi clients connect, pull down guide, channel icons, etc. but when they go to play a channel, it spins for a few seconds then stops. The HDHomeRun AddOn for Kodi works fine, so I recognize that it must be something in my ServerWMC configuration. Please find below the most recent log when attempting to open a channel. Any thoughts or guidance would be greatly appreciated.
2016/02/03 07:54:21.053 OpenLiveStream> -----------------start------------------------
2016/02/03 07:54:21.053 OpenLiveStream> client: Kodi^OpenELEC requesting live stream on channel CNNHD/788
2016/02/03 07:54:21.074 LiveRemuxStream> live-tv started
2016/02/03 07:54:21.114 SetChannel> Channel: 788 : CNNHD - DDF5 = { (788 : CNNHD - 6E50) + [ 788 : CNNHD - D6DF] }
2016/02/03 07:54:21.124 SetChannel> Tuners available for this channel: 3
2016/02/03 07:54:21.124 SetChannel> Tuner DecoyMethod: OnDemand
2016/02/03 07:54:21.124 SetChannel> ---
2016/02/03 07:54:21.124 SetChannel> Attempt: 0, Tuner: HDHomeRun Prime Tuner 1322A20B-0 / ac40a792-f305-4085-92ad-d18f1e844808
2016/02/03 07:54:21.124 SetChannel> > Encrypted: False
2016/02/03 07:54:21.134 SetChannel> > RecorderInfo found: True
2016/02/03 07:54:21.134 SetChannel> > Recorder Content Protection: PROT_COPY_FREE
2016/02/03 07:54:21.154 SetChannel> > Status: NOT Available, client: playback\recorderbroker&ehshell.exe&2456
2016/02/03 07:54:21.154 SetChannel> ---
2016/02/03 07:54:21.154 SetChannel> Attempt: 1, Tuner: HDHomeRun Prime Tuner 1322A20B-2 / b0051200-3508-41c6-be77-aa01896a1621
2016/02/03 07:54:21.154 SetChannel> > Encrypted: False
2016/02/03 07:54:21.164 SetChannel> > RecorderInfo found: True
2016/02/03 07:54:21.164 SetChannel> > Recorder Content Protection: PROT_COPY_FREE
2016/02/03 07:54:21.224 SetChannel> > Status: Available, client:
2016/02/03 07:54:21.224 SetChannel> *** requested number of available tuners found, stopping search ***
2016/02/03 07:54:21.224 SetChannel> ---
2016/02/03 07:54:21.224 SetChannel> available tuners found: 1 [decoys:0], requested: 1, searched: 2
2016/02/03 07:54:21.234 SetChannel> Tuner: HDHomeRun Prime Tuner 1322A20B-2 will be used for the live stream
2016/02/03 07:54:21.234 SetChannel> Recorder acquired: True
2016/02/03 07:54:21.234 SetChannel> TuneRequest set
2016/02/03 07:54:21.274 LiveRemuxStream> wtv recording started in 0.20 sec
2016/02/03 07:54:21.274 LiveRemuxStream> stream output file: LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts
2016/02/03 07:54:21.274 LiveRemuxStream> started remux thread: 'CNNHD-788:56821'
2016/02/03 07:54:21.355 Remux::Start> Starting descriptor scan...
2016/02/03 07:54:21.385 Remux::FindDescriptors> Scanning wtv for streams...
2016/02/03 07:54:23.545 Parse> Guid: 0 took 2.02 sec, it was attempted 199 times
2016/02/03 07:54:23.585 Parse> Next 4 Guids: 0.04 sec, 0.00 sec, 0.00 sec, 0.00 sec,
2016/02/03 07:54:23.766 Parse> Language 'eng' for stream Id 25
2016/02/03 07:54:23.796 WaitUntilTrueOrTimeout> remux data found
2016/02/03 07:54:24.801 Parse> Total Descriptor parse time: 3.27 sec
2016/02/03 07:54:24.801 Pass Type: 'Descriptor':
2016/02/03 07:54:24.801 > WtvToPesDemuxer:arse> total guid headers processed: 500 (Min:500 - Max:2,000)
2016/02/03 07:54:24.811 > WtvToPesDemuxer:arse> total data packets processed: 113
2016/02/03 07:54:24.811 Remux::FindDescriptors> wtv scanned (3.43 sec), Streams found:
2016/02/03 07:54:24.821 > Audio: ID:25 (eng) ac3 5.1 48000 Hz 448 kb/s
2016/02/03 07:54:24.821 > Video: ID:26 mpeg2video MP-HL 1920x1080i fps: 30000/1001 AR: 16:9
2016/02/03 07:54:24.821 > SubTitle: ID:27 ClosedCaption
2016/02/03 07:54:24.821 Remux::FindDescriptors> Output streams:
2016/02/03 07:54:24.821 > Audio: ID:25 (eng) ac3 5.1 48000 Hz 448 kb/s
2016/02/03 07:54:24.821 > Video: ID:26 mpeg2video MP-HL 1920x1080i fps: 30000/1001 AR: 16:9
2016/02/03 07:54:24.821 Remux::FindDescriptors> ended successfully.
2016/02/03 07:54:24.851 GetLinearStream> Stream used: ID:25 (eng) ac3 5.1 48000 Hz 448 kb/s
2016/02/03 07:54:24.881 Remux::Start> Starting data remux...
2016/02/03 07:54:24.961 WriteChunk> first output file write occurred
2016/02/03 07:54:25.001 LiveRemuxStream> 'ts' file created, size: 262,144 in 3.73 sec
2016/02/03 07:54:25.001 LiveRemuxStream> total time: 3.93 sec
2016/02/03 07:54:25.011 OpenLiveStream> stream path returned to client: smb://LIVETVSERVER/Users/Public/Recorded TV/TempSWMC/LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts
2016/02/03 07:54:25.011 OpenLiveStream> -----------------done-------------------------
2016/02/03 07:54:25.011 Finished request OpenLiveStream in 3.98s
2016/02/03 07:54:25.052 Received client request: OpenELEC|192.168.35.15|StreamStartError|smb://LIVETVSERVER/Users/Public/Recorded TV/TempSWMC/LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts
2016/02/03 07:54:25.052 StreamStartError> client 'Kodi^OpenELEC' reports error opening stream, will close stream down
2016/02/03 07:54:25.052 StreamStartError> client 'Kodi^OpenELEC' path to stream file: 'smb://LIVETVSERVER/Users/Public/Recorded TV/TempSWMC/LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts'
2016/02/03 07:54:25.052 StreamStartError> client 'Kodi^OpenELEC' calling CloseStream
2016/02/03 07:54:25.072 Remux::Stop> stop remux requested
2016/02/03 07:54:25.082 WtvToPesDemuxer:arse> Guid header detects stream end
2016/02/03 07:54:25.082 Pass Type: 'Remux':
2016/02/03 07:54:25.082 > WtvToPesDemuxer:arse> total guid headers processed: 540
2016/02/03 07:54:25.082 > WtvToPesDemuxer:arse> total data packets processed: 70
2016/02/03 07:54:25.092 Remux> ENDED, >>>>>>>>>> Run Time: 0.00 min <<<<<<<<<<
2016/02/03 07:54:25.102 LiveRemuxStream::Close> remux stopped successfully
2016/02/03 07:54:25.172 DeleteTS> ts file size: 1,310,720
2016/02/03 07:54:25.172 LiveRemuxStream::Close> ts file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.ts
2016/02/03 07:54:25.182 RecordToWTV::Close> isPassive is False => COM recorder will be stopped
2016/02/03 07:54:25.293 LiveRemuxStream::Close> wtv closed successfully
2016/02/03 07:54:25.353 LiveRemuxStream::Close> wtv file size: 2,097,152 (0x200000)
2016/02/03 07:54:25.353 LiveRemuxStream::Close> wtv file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Kodi^OpenELEC_Digital Cable_788_2016_02_03_07_54_21.wtv
2016/02/03 07:54:25.353 LiveRemuxStream::Close> closed in 0.29 sec
2016/02/03 07:54:25.353 Close> closed stream for client: Kodi^OpenELEC
2016/02/03 07:54:25.353 Finished request StreamStartError in 0.30s