Watching Channel, stopping, and after some time try again same channel errors out

[aderlopas]

Hello,

Seems Kodi/Nextpvr addon may have some issue repeatedly requesting channels after some time.

Opened Fresh Kodi 18 Alpha pre-release on my Win 10 64bit (April creator's update).

Opened channel, watched for some time.

Stopped channel, and let it for 3-5 minutes alone.
Then tried to re-open the same channel and from there on got "Tuner no longer available error" until I closed Kodi and re-opened it again.

Kodi Logs show:

16:50:37.959 T:9104 DEBUG: CAddonCallbacksAddon - KodiAPI::AddOn::CAddonCallbacksAddon::QueueNotification - NextPVR PVR Client - Error Message : 'Tuner no longer available'
16:50:37.959 T:9104 ERROR: ffmpeg[2390]: [NULL] SPS unavailable in decode_picture_timing
16:50:37.959 T:9104 ERROR: ffmpeg[2390]: [NULL] non-existing PPS 0 referenced
16:50:37.959 T:9104 DEBUG: CVideoPlayer::HandleMessages - player 1 reported state: 0
16:50:37.972 T:4052 DEBUG: Previous line repeats 2 times.

NPVR weblog shows:

2018-05-13 16:50:16.571 [DEBUG][56] ********** Checking VLC Heartbeat Dictionary
2018-05-13 16:50:16.571 [DEBUG][56] +++++No entries in VLC Heartbeat Dictionary.
2018-05-13 16:50:18.967 [DEBUG][58] Got Web Request (::ffff:192.168.178.29): /service method=recording.lastupdated&sid=1a0452d3c538403abd3cc456e4fb99e4
2018-05-13 16:50:18.967 [DEBUG][58] method=recording.lastupdated
2018-05-13 16:50:18.967 [DEBUG][58] parameters:
2018-05-13 16:50:18.967 [DEBUG][58] method: recording.lastupdated
2018-05-13 16:50:18.967 [DEBUG][58] sid: 1a0452d3c538403abd3cc456e4fb99e4
2018-05-13 16:50:18.967 [DEBUG][58] client_ip: 192.168.178.29
2018-05-13 16:50:18.967 [DEBUG][58] host_callback: 192.168.178.41:8866
2018-05-13 16:50:18.967 [DEBUG][58] physical_path: C:\Users\Public\NPVR\web\
2018-05-13 16:50:18.967 [DEBUG][58] user_agent: Kodi/18.0-ALPHA1 (Windows NT 10.0.17134; Win64; x64) App_Bitness/64 Version/18.0-ALPHA1-Git:20180304-89a53e418e
2018-05-13 16:50:18.967 [DEBUG][58] range: bytes=0-
2018-05-13 16:50:18.967 [DEBUG][58] requested_path: /service
2018-05-13 16:50:18.967 [DEBUG][58] verb: GET
2018-05-13 16:50:18.967 [DEBUG][58] LastUpdated
2018-05-13 16:50:18.968 [DEBUG][58] <?xml version="1.0" encoding="utf-8" ?>
<rsp stat="ok">
<last_update>1526167647</last_update>
</rsp>

2018-05-13 16:50:46.571 [DEBUG][56] ********** Checking VLC Heartbeat Dictionary
2018-05-13 16:50:46.571 [DEBUG][56] +++++No entries in VLC Heartbeat Dictionary.
2018-05-13 16:51:16.586 [DEBUG][60] ********** Checking VLC Heartbeat Dictionary
2018-05-13 16:51:16.586 [DEBUG][60] +++++No entries in VLC Heartbeat Dictionary.
2018-05-13 16:51:46.586 [DEBUG][56] ********** Checking VLC Heartbeat Dictionary
2018-05-13 16:51:46.586 [DEBUG][56] +++++No entries in VLC Heartbeat Dictionary.

Nrecord.log shows nothing after the first time I stopped the stream...(16:40)

2018-05-13 16:40:05.528 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:05.528 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:10.562 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:15.599 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:20.633 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:25.666 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:30.697 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:35.729 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:40.858 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:45.888 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:49.603 [DEBUG][67] StopStream(F)

Any ideas? Attached full logs.

[aderlopas]

Hello,

Seems Kodi/Nextpvr addon may have some issue repeatedly requesting channels after some time.

Opened Fresh Kodi 18 Alpha pre-release on my Win 10 64bit (April creator's update).

Opened channel, watched for some time.

Stopped channel, and let it for 3-5 minutes alone.
Then tried to re-open the same channel and from there on got "Tuner no longer available error" until I closed Kodi and re-opened it again.

Kodi Logs show:

16:50:37.959 T:9104 DEBUG: CAddonCallbacksAddon - KodiAPI::AddOn::CAddonCallbacksAddon::QueueNotification - NextPVR PVR Client - Error Message : 'Tuner no longer available'
16:50:37.959 T:9104 ERROR: ffmpeg[2390]: [NULL] SPS unavailable in decode_picture_timing
16:50:37.959 T:9104 ERROR: ffmpeg[2390]: [NULL] non-existing PPS 0 referenced
16:50:37.959 T:9104 DEBUG: CVideoPlayer::HandleMessages - player 1 reported state: 0
16:50:37.972 T:4052 DEBUG: Previous line repeats 2 times.

NPVR weblog shows:

2018-05-13 16:50:16.571 [DEBUG][56] ********** Checking VLC Heartbeat Dictionary
2018-05-13 16:50:16.571 [DEBUG][56] +++++No entries in VLC Heartbeat Dictionary.
2018-05-13 16:50:18.967 [DEBUG][58] Got Web Request (::ffff:192.168.178.29): /service method=recording.lastupdated&sid=1a0452d3c538403abd3cc456e4fb99e4
2018-05-13 16:50:18.967 [DEBUG][58] method=recording.lastupdated
2018-05-13 16:50:18.967 [DEBUG][58] parameters:
2018-05-13 16:50:18.967 [DEBUG][58] method: recording.lastupdated
2018-05-13 16:50:18.967 [DEBUG][58] sid: 1a0452d3c538403abd3cc456e4fb99e4
2018-05-13 16:50:18.967 [DEBUG][58] client_ip: 192.168.178.29
2018-05-13 16:50:18.967 [DEBUG][58] host_callback: 192.168.178.41:8866
2018-05-13 16:50:18.967 [DEBUG][58] physical_path: C:\Users\Public\NPVR\web\
2018-05-13 16:50:18.967 [DEBUG][58] user_agent: Kodi/18.0-ALPHA1 (Windows NT 10.0.17134; Win64; x64) App_Bitness/64 Version/18.0-ALPHA1-Git:20180304-89a53e418e
2018-05-13 16:50:18.967 [DEBUG][58] range: bytes=0-
2018-05-13 16:50:18.967 [DEBUG][58] requested_path: /service
2018-05-13 16:50:18.967 [DEBUG][58] verb: GET
2018-05-13 16:50:18.967 [DEBUG][58] LastUpdated
2018-05-13 16:50:18.968 [DEBUG][58] <?xml version="1.0" encoding="utf-8" ?>
<rsp stat="ok">
<last_update>1526167647</last_update>
</rsp>

2018-05-13 16:50:46.571 [DEBUG][56] ********** Checking VLC Heartbeat Dictionary
2018-05-13 16:50:46.571 [DEBUG][56] +++++No entries in VLC Heartbeat Dictionary.
2018-05-13 16:51:16.586 [DEBUG][60] ********** Checking VLC Heartbeat Dictionary
2018-05-13 16:51:16.586 [DEBUG][60] +++++No entries in VLC Heartbeat Dictionary.
2018-05-13 16:51:46.586 [DEBUG][56] ********** Checking VLC Heartbeat Dictionary
2018-05-13 16:51:46.586 [DEBUG][56] +++++No entries in VLC Heartbeat Dictionary.

Nrecord.log shows nothing after the first time I stopped the stream...(16:40)

2018-05-13 16:40:05.528 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:05.528 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:10.562 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:15.599 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:20.633 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:25.666 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:30.697 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:35.729 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:40.858 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:45.888 [DEBUG][67] Renew lease ok (0x19000F)
2018-05-13 16:40:49.603 [DEBUG][67] StopStream(F)

Any ideas? Attached full logs.

According to:

#5667 closed defect (invalid)
MPEG-TS - SPS unavailable in decode_picture_timing non-existing PPS 0 referenced

"These kind of errors in the log are "normal" for mpeg-ts files and just a sign of a bad cut, it should start playing after it skipped the broken part."

But why would there be a "bad" cut in the .ts file ?

[sub]

But why would there be a "bad" cut in the .ts file ?

Either because that's the way the broadcaster produced it (and Kodi has an issue with it), or you had some signal issues and the device dropped some packets (and kodi had an issue with it).

[aderlopas]

Either because that's the way the broadcaster produced it (and Kodi has an issue with it), or you had some signal issues and the device dropped some packets (and kodi had an issue with it).

Hello sub,

Thanks for your reply. Problem is that this happens every time I follow this process, i.e. watch, stop, let it wait, and try to watch again.
Signal should not be a problem, as if I restart kodi it works fine again.
I think that .ts is cut because stream is cut from nextpvr. Why would it error our with Tuner no longer available?

Does it try to play the old .ts file perhaps instead of creating a new one?

[sub]

I was only commenting on the "MPEG-TS - SPS unavailable in decode_picture_timing non-existing PPS 0 referenced" message. It's fairly normal to get these directly from the transport stream content the broadcaster is producing. (ie, nothing NextPVR is doing to make this happen)

I haven't looked at your logs for the cause of your 'Tuner no longer available' message.

[sub]

It looks like you're using Kodi 18 Alpha 1, which is pretty dated now. Might be worth trying the nightly builds. mlburgett has submitted some fairly substantial updates to the Kodi 18 NextPVR addon live streaming about a week ago.

[aderlopas]

It looks like you're using Kodi 18 Alpha 1, which is pretty dated now. Might be worth trying the nightly builds. mlburgett has submitted some fairly substantial updates to the Kodi 18 NextPVR addon live streaming about a week ago.

Thanks sub,
I tried with the latest nightly, and it seems it works with the same channel. However, if afterwards I switch to another channel, it is no more streaming and I get the below error in kodi.log:

11:12:56.365 T:704 DEBUG: ------ Window Init (Pointer.xml) ------
11:12:56.790 T:2548 DEBUG: CIRServerSuite::Connect: connecting to: ::1:24000 ...
11:12:57.796 T:2548 DEBUG: CIRServerSuite::Connect: connecting to: 127.0.0.1:24000 ...
11:13:01.418 T:2548 DEBUG: CIRServerSuite::Connect: failed to connect
11:13:01.418 T:2548 INFO: CIRServerSuite:rocess: failed to connect to irss, will keep retrying every 5 seconds
11:13:05.619 T:704 DEBUG: ------ Window Deinit (Pointer.xml) ------
11:13:06.421 T:2548 DEBUG: CIRServerSuite::Connect: connecting to: ::1:24000 ...
11:13:07.425 T:2548 DEBUG: CIRServerSuite::Connect: connecting to: 127.0.0.1:24000 ...
11:13:08.467 T:2548 DEBUG: CIRServerSuite::Connect: failed to connect
11:13:08.930 T:2548 INFO: CIRServerSuite:rocess: failed to connect to irss, will keep retrying every 5 seconds

Why would it ever need to connect to localhost I wonder?

[sub]

Thanks sub,
I tried with the latest nightly, and it seems it works with the same channel. However, if afterwards I switch to another channel, it is no more streaming

You might be best to ask mlburgett. I'm not that familiar with how the new streaming stuff works in the NextPVR addon. Not sure if he's regularly here, or if you'll need to PM him on the Kodi forums.

11:12:56.365 T:704 DEBUG: ------ Window Init (Pointer.xml) ------
11:12:56.790 T:2548 DEBUG: CIRServerSuite::Connect: connecting to: ::1:24000 ...
11:12:57.796 T:2548 DEBUG: CIRServerSuite::Connect: connecting to: 127.0.0.1:24000 ...
11:13:01.418 T:2548 DEBUG: CIRServerSuite::Connect: failed to connect
11:13:01.418 T:2548 INFO: CIRServerSuite:rocess: failed to connect to irss, will keep retrying every 5 seconds
11:13:05.619 T:704 DEBUG: ------ Window Deinit (Pointer.xml) ------
11:13:06.421 T:2548 DEBUG: CIRServerSuite::Connect: connecting to: ::1:24000 ...
11:13:07.425 T:2548 DEBUG: CIRServerSuite::Connect: connecting to: 127.0.0.1:24000 ...
11:13:08.467 T:2548 DEBUG: CIRServerSuite::Connect: failed to connect
11:13:08.930 T:2548 INFO: CIRServerSuite:rocess: failed to connect to irss, will keep retrying every 5 seconds

Why would it ever need to connect to localhost I wonder?

This is nothing to do with the NextPVR stuff. It looks like Kodi is trying to connecting to some optional local daemon process, which is something to do with either IR or HDMI-CEC. It probably just to let it know video playback has ended or something.

[aderlopas]

Thanks sub for your reply. I checked those error messages and I found that it might have to do with graphics card drivers.
So I updated mine on the client PC, and I also re-scanned all the channels on all the TV sticks, and it now works I think...