Live TV not working but recordings work fine.

[mule007]

Hello all,

I have to confess, Live TV has never really worked properly for me. It always tunes to the channel, but after what appears to be a multiple of 7 minutes (7, 14, 21, etc, randomly) the image will freeze and I have to hit stop and start playback over again.

It seems now however (coincidentally since upgrading to 3.2.9, but I can't definitively say that is the cause) that Live TV does not work at all. If I attempt to hit either Live TV, or pick Watch from the TV Guide, the client will simple say "...Please wait..." and just sit there until I eventually have to kill the task.

This only happens with Live TV. If I chose to Record the show, I can go into the Recordings and watch the show from there.

I've been using an 8 Gb RAM disk as my Live TV buffer (permissions are set to grant Everyone Full Access), but decided to switch that to a temp folder on the hard disk (C:\Temp, also Everyone with Full Access) to see if that was the cause, but the issue is the same.

I don't really know how else to go about debugging it so I thought I would post here and see if anyone might have some insight into what the issue may be.

The capture device is a Hauppauge HD-PVR, and here are all of the log entries from NRecord on the server. I noticed a bunch of "File length is still zero." entries, so I suspect this is where the problem is.


Here are the log entries:

2014-05-06 13:32:32.189 [DEBUG][59] GetExtraInfo: /Settings/Recording/ExtraRecordingDirectories
2014-05-06 13:32:32.189 [DEBUG][59] GetExtraInfo@exit
2014-05-06 13:32:35.481 [DEBUG][32] GetExtraInfo: /Settings/Recording/ClientMode
2014-05-06 13:32:35.481 [DEBUG][32] GetExtraInfo@exit
2014-05-06 13:32:35.496 [DEBUG][32] StartStream(7385:SPACEC)
2014-05-06 13:32:35.496 [DEBUG][32] looking for capture source
2014-05-06 13:32:35.496 [DEBUG][32] checking: IPTV Device
2014-05-06 13:32:35.496 [DEBUG][32] enabled and present
2014-05-06 13:32:35.496 [DEBUG][32] does not have channel
2014-05-06 13:32:35.496 [DEBUG][32] checking: Hauppauge HD-PVR
2014-05-06 13:32:35.496 [DEBUG][32] enabled and present
2014-05-06 13:32:35.496 [DEBUG][32] has channel
2014-05-06 13:32:35.496 [DEBUG][32] live tv is possible
2014-05-06 13:32:35.496 [DEBUG][32] LoadListingByAdvancedRules(channel=7385,advancedRules=end_time > '2014-05-06 19:32:35')
2014-05-06 13:32:35.496 [DEBUG][32] SQL: select * from EPG_EVENT where channel_oid = 7385 and end_time > '2014-05-06 19:32:35' order by start_time
2014-05-06 13:32:35.512 [DEBUG][32] 'EPG Based' timeshift requested. Took 15.5993ms to find upcoming shows. 200 shows pending.
2014-05-06 13:32:35.512 [DEBUG][32] first up is: Castle
2014-05-06 13:32:35.512 [DEBUG][32] new target is: LIVE&C:\Temp\Castle_20140506_13321400.ts
2014-05-06 13:32:35.512 [INFO][32] HDPVRRecorder.StartStream(LIVE&C:\Temp\Castle_20140506_13321400.ts)
2014-05-06 13:32:35.512 [INFO][32] Running blaster: C:\Program Files (x86)\NPVR\HaupBlast.exe 627
2014-05-06 13:32:39.006 [DEBUG][32] About to tune graph to:
<tuning>
<type>HDPVR</type>
<locator>
<channel>627</channel>
<input>1</input>
<audio_input>SPDIF</audio_input>
<blaster_executable>C:\Program Files (x86)\NPVR\HaupBlast.exe</blaster_executable>
<blaster_args>{channel}</blaster_args>
</locator>
</tuning>

2014-05-06 13:32:39.006 [INFO][32] Creating graph
2014-05-06 13:32:39.006 [DEBUG][32] Building graph using: Hauppauge HD PVR Crossbar (245948340)
2014-05-06 13:32:39.006 [DEBUG][32] setting video routing (videoInput=1)
2014-05-06 13:32:39.022 [DEBUG][32] setting HDPVR audio routing
2014-05-06 13:32:39.022 [DEBUG][32] using 'Audio SPDIFDigital In' Audio (SPDIF)
2014-05-06 13:32:39.084 [DEBUG][32] Graph filter list:
2014-05-06 13:32:39.084 [DEBUG][32] - NPVR Writer2
2014-05-06 13:32:39.084 [DEBUG][32] - NPVR Writer
2014-05-06 13:32:39.084 [DEBUG][32] - Infinite Pin Tee Filter
2014-05-06 13:32:39.084 [DEBUG][32] - Hauppauge HD PVR Encoder
2014-05-06 13:32:39.084 [DEBUG][32] - Hauppauge HD PVR Capture Device
2014-05-06 13:32:39.084 [DEBUG][32] - Hauppauge HD PVR Crossbar
2014-05-06 13:32:39.084 [DEBUG][32] Graph Connections
2014-05-06 13:32:39.084 [DEBUG][32] Filter [a9c2134] 'NPVR Writer2'
2014-05-06 13:32:39.084 [DEBUG][32] Pin [aa16314] 'Input' [I] Connected to [6c188cc]
2014-05-06 13:32:39.084 [DEBUG][32] Filter [a9c1e34] 'NPVR Writer'
2014-05-06 13:32:39.084 [DEBUG][32] Pin [aa74b1c] 'Input' [I] Connected to [6bfdbc4]
2014-05-06 13:32:39.084 [DEBUG][32] Filter [6c607f4] 'Infinite Pin Tee Filter'
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c6085c] 'Input' [I] Connected to [6c18604]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6bfdbc4] 'Output1' [O] Connected to [aa74b1c]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c188cc] 'Output2' [O] Connected to [aa16314]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c67294] 'Output3' [O]
2014-05-06 13:32:39.084 [DEBUG][32] Filter [6c6587c] 'Hauppauge HD PVR Encoder'
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c18604] 'H.264 Out' [O] Connected to [6c6085c]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c3d034] 'Virtual Video In' [I] Connected to [6c66fcc]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c2af5c] 'Virtual Audio In' [I] Connected to [6c44d74]
2014-05-06 13:32:39.084 [DEBUG][32] Filter [6c653e4] 'Hauppauge HD PVR Capture Device'
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c66fcc] 'Virtual Video Out' [O] Connected to [6c3d034]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c44d74] 'Virtual Audio Out' [O] Connected to [6c2af5c]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c5edf4] 'Analog Video In' [I] Connected to [6c43eb4]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c5f5f4] 'Analog Audio In' [I] Connected to [6c43fdc]
2014-05-06 13:32:39.084 [DEBUG][32] Filter [6c06a34] 'Hauppauge HD PVR Crossbar'
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c1b554] '0: Video YRYBY In' [I]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c1b6bc] '1: Video SVideo In' [I]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c1b824] '2: Video Composite In' [I]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c1b98c] '3: Audio SPDIFDigital In' [I]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c1baf4] '4: Audio Line In' [I]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c1bc5c] '5: Audio AUX In' [I]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c43eb4] '0: Video Decoder Out' [O] Connected to [6c5edf4]
2014-05-06 13:32:39.084 [DEBUG][32] Pin [6c43fdc] '1: Audio Decoder Out' [O] Connected to [6c5f5f4]
2014-05-06 13:32:39.084 [INFO][32] About to start graph
2014-05-06 13:32:39.115 [DEBUG][32] Device reports resolution: 720x480 (fps:30)
2014-05-06 13:32:39.115 [DEBUG][32] device minimum bitrate: 200000
2014-05-06 13:32:39.115 [DEBUG][32] device maximum bitrate: 13500000
2014-05-06 13:32:39.115 [DEBUG][32] device bitrate step size: 100000
2014-05-06 13:32:39.131 [DEBUG][32] device reports current bitrate as: 5000000
2014-05-06 13:32:39.146 [DEBUG][32] device reports current peak bitrate as: 7500000
2014-05-06 13:32:39.146 [DEBUG][32] About to set BITRATE MODE
2014-05-06 13:32:39.162 [DEBUG][32] requesting constant encoding
2014-05-06 13:32:39.193 [DEBUG][32] trying to request bitrate: 5000000
2014-05-06 13:32:39.256 [DEBUG][32] device confirms bitrate as: 5000000
2014-05-06 13:32:39.396 [DEBUG][32] About to switch HDPVR/Colossus to target:
LIVE&C:\Temp\Castle_20140506_13321400.ts
2014-05-06 13:32:39.425 [INFO][32] HDPVR stream count now 1
2014-05-06 13:32:39.426 [DEBUG][32] Live TV handle: 0x140021
2014-05-06 13:32:39.521 [DEBUG][48] ClientConnectionHandler started...
2014-05-06 13:32:39.521 [DEBUG][48] increased send socket send buffer
2014-05-06 13:32:39.532 [DEBUG][48] ClientConnectionHandler exiting...
2014-05-06 13:32:39.534 [DEBUG][25] ClientConnectionHandler started...
2014-05-06 13:32:39.535 [DEBUG][25] increased send socket send buffer
2014-05-06 13:32:39.734 [DEBUG][25] CLIENT-OPEN: C:\Temp\Castle_20140506_13321400.ts
2014-05-06 13:32:39.734 [DEBUG][25] CLIENT-OPEN@1
2014-05-06 13:32:39.734 [DEBUG][25] CLIENT-OPEN@2
2014-05-06 13:32:39.734 [DEBUG][25] CLIENT-OPEN@3
2014-05-06 13:32:39.734 [DEBUG][25] SharedMemoryHelper::Open(): C:\Temp\Castle_20140506_13321400.ts
2014-05-06 13:32:39.734 [DEBUG][25] OpenFileMapping: Global\NPVRSlip5c436173746c655f32303134303530365f31333332313430302e7473
2014-05-06 13:32:39.734 [DEBUG][25] Got file mapping
2014-05-06 13:32:39.734 [DEBUG][25] got shared memory helper
2014-05-06 13:32:39.735 [DEBUG][25] CLIENT-OPEN@using shared memory
2014-05-06 13:32:39.735 [DEBUG][25] CLIENT-OPEN@6
2014-05-06 13:32:39.735 [DEBUG][25] RollingFile(C:\Temp\Castle_20140506_13321400.ts)..
2014-05-06 13:32:39.735 [DEBUG][25] Rolling file extended logging enabled
2014-05-06 13:32:39.735 [DEBUG][25] CLIENT-OPEN@ file opened
2014-05-06 13:32:39.735 [DEBUG][25] CLIENT-OPEN: file size is 0
2014-05-06 13:32:39.935 [DEBUG][25] File length is still zero.
(Still zero line repeats about 20 more times)
2014-05-06 13:32:43.935 [DEBUG][25] File length is now: 0
2014-05-06 13:32:43.935 [DEBUG][25] CLIENT-READ: 0 bytes from offset 0 (file length: 0)
2014-05-06 13:32:43.935 [DEBUG][25] RollingFile.Seek(0)
2014-05-06 13:32:43.935 [DEBUG][25] RollingFile base offset is now: 0
2014-05-06 13:32:43.935 [DEBUG][25] <Files>
<Length>0</Length>
<File offset="0">C:\Temp\Castle_20140506_13321400.ts</File>
<Duration>0</Duration>
<Complete>0</Complete>
</Files>

2014-05-06 13:32:43.935 [DEBUG][25] about to read 0 from location 0 (current length = 0)
2014-05-06 13:32:43.936 [DEBUG][25] GetDurationMS() live: 0
2014-05-06 13:32:43.936 [DEBUG][25] READ: data read, about to send
2014-05-06 13:32:43.936 [DEBUG][25] READabout to send 0 bytes, from offset 0
2014-05-06 13:32:43.936 [DEBUG][25] READ: complete

[mvallevand]

Does it work on the host server running NextPVR there?

Martin

[mule007]

I *think* it works properly from the server.

The server is headless, I only access it via RDP so the playback is a black screen, but its not hanging on Please Wait, and the logs look different, which tells me that its working, but only makes me more confused as to why it won't work on the client connected to the TV.

Here is the bit of the log that is different playing from the server:

2014-05-06 15:57:29.440 [DEBUG][48] About to switch HDPVR/Colossus to target:
LIVE&C:\Temp\Global National_20140506_15571600.ts
2014-05-06 15:57:29.466 [INFO][48] HDPVR stream count now 1
2014-05-06 15:57:29.467 [DEBUG][48] Live TV handle: 0x140023
2014-05-06 15:57:39.618 [DEBUG][48] Renew lease ok (0x140023)
2014-05-06 15:57:49.786 [DEBUG][48] Renew lease ok (0x140023)
2014-05-06 15:57:59.950 [DEBUG][48] Renew lease ok (0x140023)
2014-05-06 15:58:10.121 [DEBUG][48] Renew lease ok (0x140023)
2014-05-06 15:58:20.295 [DEBUG][48] Renew lease ok (0x140023)
2014-05-06 15:58:30.614 [DEBUG][48] Renew lease ok (0x140023)
2014-05-06 15:58:32.316 [INFO][48] HDPVRRecorder.StopStream(35)
2014-05-06 15:58:32.316 [INFO][48] HDPVR/Colossus stream count now 0
2014-05-06 15:58:32.316 [DEBUG][48] Graph stopping...
2014-05-06 15:58:35.238 [DEBUG][48] Graph stopped
2014-05-06 15:58:35.238 [DEBUG][48] Removing filter NPVR Writer2
2014-05-06 15:58:35.238 [DEBUG][48] Removing filter NPVR Writer
2014-05-06 15:58:35.238 [DEBUG][48] Removing filter Infinite Pin Tee Filter
2014-05-06 15:58:35.241 [DEBUG][48] Removing filter Hauppauge HD PVR Encoder
2014-05-06 15:58:35.242 [DEBUG][48] Removing filter Hauppauge HD PVR Capture Device
2014-05-06 15:58:35.244 [DEBUG][48] Removing filter Hauppauge HD PVR Crossbar