Issue accessing channels from IPTV device

[thool]

Client:
NextPVR 19.0.6.1
LibreELEC 10.0.4, RPi4.arm
Confluence 4.7.13
Kodi 19.5

Backend:
NextPVR Version: 6.1.1.221106
Ubuntu 20.04.6 LTS x86_64
Kernel: 5.4.0-147-generic

Using backend UI, set up an IPTV Device pointing to https://iptv-org.github.io/iptv/countries/us.m3u. Scanned and found 1669 channels.

What works:
Can access OTA channels through NextPVR backend UI "guide" menu. Can do the same via the RPi client. So I'm confident my OTA realtime playback and recordings work fine.

What doesn't work:
Cannot access any of the IPTV content, neither through the NextPVR backend "guide" menu nor through the client on the RPi. The client message: "One or more items failed to play. Check the log for more information about this message." Trying from backend UI Guide (watch now) get: "Error starting transcode: error: Internal Server Error" along with these 2 lines in kodi.log
2023-04-23 12:07:00.147 T:824    ERROR <general>: CCurlFile::FillBuffer - Failed: Couldn't connect to server(7)
2023-04-23 12:07:00.148 T:824    ERROR <general>: CCurlFile::Open failed with code 0 for http://192.168.1.83:8866/service?method=...548e9b1631:

What I've tried:
Updated backend, rebooted
Updated frontend LibreELEC, bootloader, USB3, rebooted
Deleted IPTV device, added new
Empty EPG, update EPG
At a high level, network is good: Ping the backend from the frontend
Did "update channels" and save


The kodi.log rows that appeared when tailing:
2023-04-23 11:43:22.629 T:798      INFO <general>: CActiveAESink::OpenSink - initialize sink                                                                                                         
2023-04-23 11:43:22.629 T:798      INFO <general>: CAESinkALSA::Initialize - Attempting to open device "default"                                                                                     
2023-04-23 11:43:22.636 T:798      INFO <general>: CAESinkALSA::Initialize - Opened device "default"                                                                                                 
2023-04-23 11:43:22.638 T:798      INFO <general>: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats                                                     
2023-04-23 11:43:22.638 T:798      INFO <general>: CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE3                                                                                       
2023-04-23 11:43:39.167 T:792      INFO <general>: VideoPlayer::OpenFile: pvr://channels/tv/All%20channels/pvr.nextpvr_18467.pvr                                                                     
2023-04-23 11:43:39.169 T:1013    INFO <general>: Creating InputStream                                                                                                                             
2023-04-23 11:43:39.169 T:1013    ERROR <general>: AddOnLog: pvr.nextpvr: Unknown live streaming state 0 0 1                                                                                         
2023-04-23 11:43:39.169 T:1013    INFO <general>: AddOnLog: pvr.nextpvr: Calling Open(http://192.168.1.83:8866/live?channeloid...548e9b1631) on tsb!         
2023-04-23 11:43:39.187 T:1013    ERROR <general>: CCurlFile::Open failed with code 404 for http://192.168.1.83:8866/live?channeloid...548e9b1631:             
                                                                                                                                                                                                     
2023-04-23 11:43:39.188 T:1013    ERROR <general>: CVideoPlayer::OpenInputStream - error opening [pvr://channels/tv/All%20channels/pvr.nextpvr_18467.pvr]                                           
2023-04-23 11:43:39.188 T:1013    INFO <general>: CVideoPlayer::OnExit()                                                                                                                           
2023-04-23 11:43:39.262 T:792      INFO <general>: CVideoPlayer::CloseFile()                                                                                                                         
2023-04-23 11:43:39.262 T:792      INFO <general>: VideoPlayer: waiting for threads to exit                                                                                                         
2023-04-23 11:43:39.262 T:792      INFO <general>: VideoPlayer: finished waiting       


Correlating rows in nrecord.log:
2023-04-23 11:43:39.153 [DEBUG][66] Got request [192.168.1.61]: /live
2023-04-23 11:43:39.153 [DEBUG][66] /live?channeloid=18467&client=XBMC-1b9679319ca547b49b708c548e9b1631
2023-04-23 11:43:39.153 [DEBUG][66] - channeloid: 18467
2023-04-23 11:43:39.153 [DEBUG][66] - client: XBMC-1b9679319ca547b49b708c548e9b1631
2023-04-23 11:43:39.153 [DEBUG][66] range: bytes=0-
2023-04-23 11:43:39.153 [DEBUG][66] Checking XBMC sid: 1b9679319ca547b49b708c548e9b1631
2023-04-23 11:43:39.153 [DEBUG][66] StreamNative@1..
2023-04-23 11:43:39.153 [DEBUG][66] StreamNative@2
2023-04-23 11:43:39.153 [DEBUG][66] StreamNative@3
2023-04-23 11:43:39.153 [DEBUG][66] StreamNative@4
2023-04-23 11:43:39.153 [DEBUG][66] StreamNative@5
2023-04-23 11:43:39.167 [DEBUG][66] StreamNative@6
2023-04-23 11:43:39.167 [DEBUG][66] StreamNative@7...
2023-04-23 11:43:39.167 [DEBUG][66] StreamNative@8 (/mnt/recordings/live-Access Humboldt (1080p)-753-26.ts)
2023-04-23 11:43:39.167 [DEBUG][66] about to start stream...
2023-04-23 11:43:39.167 [DEBUG][66] StartStream(18467:Access Humboldt (1080p))
2023-04-23 11:43:39.167 [DEBUG][66] looking for capture source (in reverse priority order)
2023-04-23 11:43:39.168 [DEBUG][66] checking: IPTV (http://...)
2023-04-23 11:43:39.168 [DEBUG][66] enabled and present
2023-04-23 11:43:39.168 [DEBUG][66] does not have channel
2023-04-23 11:43:39.168 [DEBUG][66] checking: IPTV (http://...)
2023-04-23 11:43:39.168 [DEBUG][66] enabled and present
2023-04-23 11:43:39.168 [DEBUG][66] does not have channel
2023-04-23 11:43:39.168 [DEBUG][66] checking: IPTV (http://...)
2023-04-23 11:43:39.168 [DEBUG][66] enabled and present
2023-04-23 11:43:39.168 [DEBUG][66] does not have channel
2023-04-23 11:43:39.168 [DEBUG][66] checking: HDHomeRun 10693538-1
2023-04-23 11:43:39.168 [DEBUG][66] enabled and present
2023-04-23 11:43:39.168 [DEBUG][66] does not have channel
2023-04-23 11:43:39.168 [DEBUG][66] checking: HDHomeRun 10693538-0
2023-04-23 11:43:39.168 [DEBUG][66] enabled and present
2023-04-23 11:43:39.168 [DEBUG][66] does not have channel
2023-04-23 11:43:39.168 [DEBUG][66] StartStream(18467:Access Humboldt (1080p), LIVE&/mnt/recordings/live-Access Humboldt (1080p)-753-26.ts) allocated handle: 0
2023-04-23 11:43:39.168 [DEBUG][66] Handle: 0
2023-04-23 11:43:39.168 [DEBUG][66] Failed to start stream. Handle 0.

[mvallevand]

Sometimes the NextPVR needs a restart to load the channel list which appears to be the case here and none of the IPTV source seem to have the channel stored. If it fails after the restart send the zipped logs not snippets.

Note I don't typically support using github URL's because the lists are often wrong and not stable, since NextPVR isn't accessing the URL the problem is elsewhere.

Martin