Live TV Suddenly Stops Playing

[jmooremcc]

I have noticed that Live TV will suddenly stop playing around the 45 minute mark. In this particular case, I started the first episode of my TV show at 12 noon and the show ended at 12:30 PM. The next episode of the same show started at 12:30 PM and was suppose to end at 1:00 PM. However around 12:45 PM the screen froze and about 2 minutes later the playback of live TV stopped, meaning I was now back to the home screen. The EPG shows the two episodes scheduled as I described. If you reference the attached Kodi Client log, the problem occurs at 2021-07-07 12:45:29.009 T:6688.

BTW, I have a similar problem when watching a 2 hour news program in the morning except the freeze occurs around the 1 hour and 40+ minute mark.

My V5 server (version: 5.1.2.219603) runs on a Windows 10 PC.
My V5 server buffer is set for 120 minutes.
The Kodi client (Kodi addon version: 8.2.3.1) runs on a Raspberry Pi 4.
The RPi 4 is running LibreELEC 9.95.5.

I hope the provided information and logs is enough for you to troubleshoot this issue.

Thanks

John


  V5logs-20210707-1247.zip (Size: 1.26 MB / Downloads: 7)

 Kodi Log

[mvallevand]

I suspect this could be another variant of this bug https://forums.nextpvr.com/showthread.php?tid=62761 the difference in timeshifting mode seems to be this log entry, which starts getting reported when you indicate playback failure.

2021-07-07 12:45:03.396 [DEBUG][37] stream@2 got zero bytes

It is not related exactly with a roll but the channel.stream.info map file does look like the file is growing so data should be available.

Sub will need to investigate this.

Martin

[johnm0101]

to add I am getting live TV stopping but regularly - three or four times during half hour programme.
I am afraid I dont understand the log but it contains severa; 'couldn't connect to server messages around the time of the error. I checked using putty and the network connection seems ok. I can remote in to hte OSMC client and to teh nextpvr machine so I dont understand this network error 
I have NextPVR on the server ver 5.1.2  - I am just updating to 5.1.3
I use OSMC (Kodi) on Raspi boxes which have ver 19
Seems to be a next pvr issue because the main tv is a large android tv (runs Kodi 19) that too has a live stream stopping issue
The nextpvr is running on a quite beefy i7 16gb ram windows 10 - always seems to present problems after a Windows update (but I havent figured that yet)
I post this in case it adds to knowledge on suggested bug. I will report again when I've installed v 5.1.3
Also I find it necessary to 'restart' the Nextpvr service frequently to avoid these probs

[mvallevand]

This was an issue in 5.1.2 for sure, but it is not clear why you don't go to 5.1.4

Martin

[johnm0101]

HI Martin
I appreciate your help
I wasn't aware I was not using the latest - call me dumb - so I'll look into it
As you can guess by the sporadic way I (and others) post - Its not like my project programming - providing it roughly works and there is no domestic strife - it works roughly so I'll leave it - I am sure this different feedback loop is a problem for clever people like you developing such a system ....
Also summer means one is out of doors and not watching the goggle box much
Mind you its now September and I will give it a bit more attention starting with v 5/14
once again many tx and appreciation for your help and unstinting support for this forum

brgds
John Murray

[mvallevand]

Typically before reporting a problem it is best to update versions and that usually can be done faster than posting uploading logs etc. Then main settings screen in NextPVR tells you if you are behind.

There will probably be a 5.1.5 before long anyway. Enjoy the rest of the summer.

Martin

[aderlopas]

Hello, 

Unfortunately it is present in the latest version too....I haveV erVersion: 5.2.1.211003 and I get the same behavior, kodi stopps suddenly after some time....

The below is in nrecord.log....(logs uploaded)..


2021-10-09 16:50:36.141 [DEBUG][35] stream@2 got zero bytes
2021-10-09 16:50:37.245 [DEBUG][35] stream@2 got zero bytes
2021-10-09 16:50:37.736 [DEBUG][74] Got request [192.168.178.43]: /service (channel.transcode.lease)
2021-10-09 16:50:37.737 [DEBUG][74] method=channel.transcode.lease
2021-10-09 16:50:37.737 [DEBUG][74] parameters:
2021-10-09 16:50:37.737 [DEBUG][74]   method: channel.transcode.lease
2021-10-09 16:50:37.737 [DEBUG][74]   sid: 66167d025b7844c5ac84ab44ba10383e
2021-10-09 16:50:37.737 [DEBUG][74]   client_ip: 192.168.178.43
2021-10-09 16:50:37.737 [DEBUG][74]   user_agent: Kodi/19.1 (Linux; Android 8.0; KSTB6077 Build/OTT1.180726.001) Android/8.0.0 Sys_CPU/armv7l App_Bitness/32 Version/19.1-(19.1.0)-Git:20210508-85e05228b4
2021-10-09 16:50:37.737 [DEBUG][74]   host_callback: ...
2021-10-09 16:50:37.737 [DEBUG][74] Renew lease ok (0x180005)
2021-10-09 16:50:37.738 [DEBUG][74] <?xml version="1.0" encoding="utf-8" ?>
<rsp stat="ok">
</rsp>



Anything we can do about this?

[mvallevand]

There is an issue but it is not quite the same issue, in this case the tuner also stopped delivering data but the log entry that NextPVR couldn't stop the device to me makes it not look more like a device problem.

2021-10-09 16:51:03.019 [DEBUG][8] Graph stopping... (async)
2021-10-09 16:51:11.020 [DEBUG][12] Async stop taking way too long

Sub does need to look at the stream@2 log issue though.

Martin

[aderlopas]

Hi Martin,
Thanks for your reply.
I did change the happauge card to a usb 2.0 and not a 3.0 port and updated the drivers to the latest ones coming with WinTV 10.
now there is no graph stopping in the log, however the same happens.
From kodi side I can see the below:
---------------
2021-10-10 19:48:20.233 T:7703    DEBUG <general>: CurlFile::Open(0x7b7b4780) http://192.168.178.77:8866/service?metho...7379cb75bb
2021-10-10 19:48:20.243 T:7703    DEBUG <general>: AddOnLog: pvr.nextpvr: DoMethodRequest channel.transcode.lease 0 66 12
2021-10-10 19:48:26.329 T:7710    INFO <general>: CVideoPlayerAudio:rocess - stream stalled
2021-10-10 19:48:27.246 T:7703    DEBUG <general>: CurlFile::Open(0x7b7b4780) http://192.168.178.77:8866/service?metho...7379cb75bb
2021-10-10 19:48:27.256 T:7703    DEBUG <general>: AddOnLog: pvr.nextpvr: DoMethodRequest channel.transcode.lease 0 66 12
2021-10-10 19:48:28.258 T:7703    DEBUG <general>: CurlFile::Open(0x7b7b4780) http://192.168.178.77:8866/service?metho...7379cb75bb
2021-10-10 19:48:28.268 T:7703    DEBUG <general>: AddOnLog: pvr.nextpvr: DoRequest return /service?method=channel.stream.info 200 687 11
2021-10-10 19:48:28.268 T:7703    DEBUG <general>: AddOnLog: pvr.nextpvr: CT channel.stream.info 711031040 1166219 0 1166219
2021-10-10 19:48:28.849 T:7719    DEBUG <general>: CDVDVideoCodecAndroidMediaCodec::SignalEndOfStream: state: 3
2021-10-10 19:48:28.849 T:7719    DEBUG <general>: CDVDVideoCodecAndroidMediaCodec::SignalEndOfStream: ReleaseMediaCodecBuffers
2021-10-10 19:48:28.850 T:7719    DEBUG <general>: CDVDVideoCodecAndroidMediaCodec::SignalEndOfStream: BUFFER_FLAG_END_OF_STREAM send
2021-10-10 19:48:28.867 T:7719    DEBUG <general>: CPtsTracker: pattern lost on diff 199999.000000, number of losses 2
2021-10-10 19:48:28.867 T:7719    DEBUG <general>: CDVDVideoCodecAndroidMediaCodec:: BUFFER_FLAG_END_OF_STREAM
-----------------------------
From nrecord.log I see the below:

--------------------------------------------
2021-10-10 19:48:29.527 [DEBUG][178] Got request [192.168.178.43]: /service (channel.transcode.lease)
2021-10-10 19:48:29.528 [DEBUG][178] method=channel.transcode.lease
2021-10-10 19:48:29.528 [DEBUG][178] parameters:
2021-10-10 19:48:29.528 [DEBUG][178]   method: channel.transcode.lease
2021-10-10 19:48:29.528 [DEBUG][178]   sid: 5bc370984f4e49d0bb44427379cb75bb
2021-10-10 19:48:29.528 [DEBUG][178]   client_ip: 192.168.178.43
2021-10-10 19:48:29.528 [DEBUG][178]   user_agent: Kodi/19.1 (Linux; Android 8.0; KSTB6077 Build/OTT1.180726.001) Android/8.0.0 Sys_CPU/armv7l App_Bitness/32 Version/19.1-(19.1.0)-Git:20210508-85e05228b4
2021-10-10 19:48:29.528 [DEBUG][178]   host_callback: ...
2021-10-10 19:48:29.528 [DEBUG][178] Renew lease ok (0x180003)
2021-10-10 19:48:29.529 [DEBUG][178] <?xml version="1.0" encoding="utf-8" ?>
<rsp stat="ok">
</rsp>

2021-10-10 19:48:31.005 [DEBUG][160] stream@2 got zero bytes
2021-10-10 19:48:32.118 [DEBUG][160] stream@2 got zero bytes
2021-10-10 19:48:33.241 [DEBUG][160] stream@2 got zero bytes
2021-10-10 19:48:34.348 [DEBUG][160] stream@2 got zero bytes
2021-10-10 19:48:35.475 [DEBUG][160] stream@2 got zero bytes
2021-10-10 19:48:36.540 [DEBUG][136] Got request [192.168.178.43]: /service (channel.transcode.lease)
2021-10-10 19:48:36.541 [DEBUG][136] method=channel.transcode.lease
2021-10-10 19:48:36.541 [DEBUG][136] parameters:
2021-10-10 19:48:36.541 [DEBUG][136]   method: channel.transcode.lease
2021-10-10 19:48:36.541 [DEBUG][136]   sid: 5bc370984f4e49d0bb44427379cb75bb
2021-10-10 19:48:36.541 [DEBUG][136]   client_ip: 192.168.178.43
2021-10-10 19:48:36.542 [DEBUG][136]   user_agent: Kodi/19.1 (Linux; Android 8.0; KSTB6077 Build/OTT1.180726.001) Android/8.0.0 Sys_CPU/armv7l App_Bitness/32 Version/19.1-(19.1.0)-Git:20210508-85e05228b4
2021-10-10 19:48:36.542 [DEBUG][136]   host_callback: ...
2021-10-10 19:48:36.542 [DEBUG][136] Renew lease ok (0x180003)
2021-10-10 19:48:36.543 [DEBUG][136] <?xml version="1.0" encoding="utf-8" ?>
<rsp stat="ok">
</rsp>

2021-10-10 19:48:36.577 [DEBUG][160] stream@2 got zero bytes
2021-10-10 19:48:37.554 [DEBUG][178] Got request [192.168.178.43]: /service (channel.stream.info)
2021-10-10 19:48:37.554 [DEBUG][178] method=channel.stream.info
2021-10-10 19:48:37.554 [DEBUG][178] parameters:
2021-10-10 19:48:37.554 [DEBUG][178]   method: channel.stream.info
2021-10-10 19:48:37.554 [DEBUG][178]   sid: 5bc370984f4e49d0bb44427379cb75bb
2021-10-10 19:48:37.554 [DEBUG][178]   client_ip: 192.168.178.43
2021-10-10 19:48:37.554 [DEBUG][178]   user_agent: Kodi/19.1 (Linux; Android 8.0; KSTB6077 Build/OTT1.180726.001) Android/8.0.0 Sys_CPU/armv7l App_Bitness/32 Version/19.1-(19.1.0)-Git:20210508-85e05228b4
2021-10-10 19:48:37.554 [DEBUG][178]   host_callback: ...
2021-10-10 19:48:37.555 [DEBUG][178] <map>
  <stream_length>711031040</stream_length>
  <stream_duration>1166219</stream_duration>
  <complete>false</complete>
  <live>true</live>
  <files>
  <file>
    <filename>R:\Temp\live-ANT1 HD-19-3.ts</filename>
    <offset>480029800</offset>
    <start_ms>802047</start_ms>
    <end_ms>802047</end_ms>
  </file>
  <file>
    <filename>R:\Temp\live-ANT1 HD-19-2.ts</filename>
    <offset>226305752</offset>
    <start_ms>401032</start_ms>
    <end_ms>401032</end_ms>
  </file>
  <file>
    <filename>R:\Temp\live-ANT1 HD-19.ts</filename>
    <offset>0</offset>
    <start_ms>0</start_ms>
    <end_ms>0</end_ms>
  </file>
  </files>
</map>
--------------------------------------------
uploading new logs...

[mvallevand]

It's a NextPVR problem not Kodi, sub needs to explain it. It is either a NextPVR read issue or the source stopped providing data

The specific scenario is this in nrecord.

2021-10-10 14:10:56.045 [DEBUG][17] stream@2 got zero bytes

matched to this in the device

2021-10-10 13:48:34.364 [DEBUG][9] locked=1, present=1, strength=62, quality=85 (took 62ms to check)
2021-10-10 13:48:34.364 [DEBUG][9] StartStream()@exit handle=17
2021-10-10 13:48:34.364 [DEBUG][9] StartStream succeded. Handle: 17
2021-10-10 14:11:00.320 [INFO][12] Got GET request: /stream/stop?handle=17
2021-10-10 14:11:00.420 [DEBUG][12] About to request async graph stop
2021-10-10 14:11:01.090 [DEBUG][12] Async stop completed successfully

Martin