[dapharsyde]

A few months ago, an update to Inputstream.adaptive finally allowed Hulu Live TV streams to work.  This has been working seamlessly for months now, but over the weekend I noticed issues with ESPN during some of their broadcasts - specifically, the NBA and NHL playoffs.  I'm noticing the same issue tonight with the Lakers vs Nuggets broadcast.  The stream loads as usual, but stops after < 30 seconds.  Unlike the issues we had before, it appears unrelated to when an advertisement is playing -- the stream always stops within 30 seconds, regardless of the content being shown.

The strange thing is that this problem occurs ONLY on the ESPN channel, and only during some broadcasts.  In fact, ESPN2 still works fine, as they're doing a simulcast of the same Lakers vs Nuggets game with different broadcasters.

What would be the best way to provide a debug log or additional information to help troubleshoot this issue?

[izprtxqkft]

you could post a Debug Log to matt in his Hulu thread - https://forum.kodi.tv/showthread.php?tid=364953

he normally requests issues be opened on his github - https://github.com/matthuisman/slyguy.addons/issues

he can instruct you further

[dapharsyde]

you could post a Debug Log to matt in his Hulu thread - https://forum.kodi.tv/showthread.php?tid=364953

he normally requests issues be opened on his github - https://github.com/matthuisman/slyguy.addons/issues

he can instruct you further

yea, i've posted in that thread before when this was an issue with ad breaks, and it required a fix to inputstream.adaptive, not the hulu plugin.  so i'm assuming the same case applies here, there's something going on with these DASH streams that inputstream.adaptive can't handle properly.

@matthuisman - can you confirm next steps to help resolve this issue?

[matthuisman]

Suspect it's due to the memory leak issue in latest inputstream adaptive. There are some test builds Glenn guy has posted around to try

https://jenkins.kodi.tv/blue/organizatio...artifacts/

[dapharsyde]

I'm using v20.3.8.1 which I think includes the fixes to the memory leak issues.  Prior to installing this version I was getting a lot of hard crashes (on all channels) likely due to the memory leaks, so I'm pretty sure that has been addressed.

However, I have still been experiencing the same sporadic issues on ESPN, but only with certain broadcasts.  Since the problem appears to be specific to the DASH stream at a particular moment in time, the next time I notice it happening, what is the best way to capture a useful debug log for the inputstream devs to look at?

[matthuisman]

are the problems showing up during adverts?

[dapharsyde]

The breaks happen after < 30 seconds during regular broadcast and adverts.  The problem appears unrelated to the chapter changes due to adverts playing.  Since the stream always dies after < 30 seconds my assumption has been that the plugin is able to download the first video segment, but nothing after that.

I don't know if this is a coincidence, but the last time this occurred it was during an ESPN broadcast on Hulu that was also available as a live ESPN+ stream.  I know this is a long shot, but could the problem lie within the fact the video stream is being served from ESPN+ servers but authentication is with Hulu's servers?

[dapharsyde]

The issue is happening right now on ESPN (~8:45PM PDT 6/5/2023).  The issue appears isolated to this channel only -- ESPN2 works without a problem, but ESPN stops streaming within 30 seconds.

I managed to capture this from the debug log when the freezes occur - these lines do not appear in the log on ESPN2, but appear within 1 minute on ESPN - hopefully this is helpful to someone who is willing to look into this?

Code:

2023-06-05 20:46:13.616 T:10410 warning <general>: OutputPicture - timeout waiting for buffer
2023-06-05 20:46:14.017 T:10410    info <general>: CDVDVideoCodecFFmpeg::CDropControl: calculated diff time: 16683
2023-06-05 20:46:16.860 T:10401   error <general>: AddOnLog: inputstream.adaptive: RefreshLiveSegments: Segment at position 0 not found from (update) representation id: EC3_1_CMAF_CENC_CTR_256K
2023-06-05 20:46:27.708 T:12337    info <general>: Skipped 3 duplicate messages..
2023-06-05 20:46:27.708 T:12337   error <general>: AddOnLog: inputstream.adaptive: RefreshLiveSegments: Segment at position 0 not found from (update) representation id: EC3_1_CMAF_CENC_CTR_256K
2023-06-05 20:46:31.096 T:10413    info <general>: Skipped 1 duplicate messages..
2023-06-05 20:46:31.096 T:10413    info <general>: CVideoPlayerAudio:rocess - stream stalled
2023-06-05 20:46:31.930 T:12364   error <general>: AddOnLog: inputstream.adaptive: RefreshLiveSegments: Segment at position 0 not found from (update) representation id: EC3_1_CMAF_CENC_CTR_256K

[dapharsyde]

it's happening again now - 6/12/2023 4:30PDT

Code:

2023-06-12 16:29:52.243 T:1562331    info <general>: Loading skin file: DialogPVRInfo.xml, load type: LOAD_EVERY_TIME
2023-06-12 16:29:52.265 T:51701   error <general>: GetDirectory - Error getting pvr://guide/0088/2023-06-12 23:00:00.epg
2023-06-12 16:29:53.127 T:1562331    info <general>: Skipped 1 duplicate messages..
2023-06-12 16:29:53.127 T:1562331    info <general>: AddOnLog: pvr.iptvsimple: pvr.iptvsimple - GetChannelStreamProperties - Live Stream URL: plugin://slyguy.hulu/?_=play_channel&channel_id=2c27a816-4404-4daf-90e0-5cf434e7e0c9&_is_live=1&_noresume=.pvr
2023-06-12 16:29:53.947 T:49609 warning <general>: Setting most video properties through ListItem.setInfo() is deprecated and might be removed in future Kodi versions. Please use the respective setter in InfoTagVideo.
2023-06-12 16:29:53.947 T:49609 warning <general>: "resumetime" in ListItem.setProperty() is deprecated and might be removed in future Kodi versions. Please use InfoTagVideo.setResumePoint().
2023-06-12 16:29:53.947 T:49609 warning <general>: "totaltime" in ListItem.setProperty() is deprecated and might be removed in future Kodi versions. Please use InfoTagVideo.setResumePoint().
2023-06-12 16:29:53.992 T:49609    info <general>: slyguy.hulu - Widevine Current MD5: b7a8561d725d43e65e0f64415c702c33
2023-06-12 16:29:53.998 T:1562331    info <general>: VideoPlayer::OpenFile: pvr://channels/tv/All%20channels/[email protected]_1573440949.pvr
2023-06-12 16:29:53.998 T:53111    info <general>: Creating InputStream
2023-06-12 16:29:53.999 T:53111 warning <general>: AddOnLog: inputstream.adaptive: Set headers to the manifest url by using pipe "|" char is deprecated, and will be removed in future.
                                                   Use "inputstream.adaptive.manifest_headers" and "inputstream.adaptive.stream_headers" properties instead.
2023-06-12 16:29:54.000 T:53111    info <general>: AddOnLog: inputstream.adaptive: [Repr. chooser] Resolution set: 1920x1080, max allowed: 1920x1080, Adjust refresh rate: 0
2023-06-12 16:29:54.000 T:53111   error <general>: GetDirectory - Error getting /usr/lib/kodi/addons/inputstream.adaptive/
2023-06-12 16:29:54.110 T:1562360    info <general>: EMBY.hooks.player: [ onPlayBackStarted ]
2023-06-12 16:29:54.573 T:53111    info <general>: AddOnLog: inputstream.adaptive: Successfully parsed manifest file (Periods: 17, Streams in first period: 3, Type: live)
2023-06-12 16:29:55.123 T:53111    info <general>: Creating Demuxer
2023-06-12 16:29:55.123 T:53111    info <general>: Opening stream: 1001 source: 256
2023-06-12 16:29:55.137 T:53111    info <general>: Creating video codec with codec id: 27
2023-06-12 16:29:55.137 T:53111    info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2023-06-12 16:29:55.138 T:53111    info <general>: Creating video thread
2023-06-12 16:29:55.138 T:53122    info <general>: running thread: video_thread
2023-06-12 16:29:55.139 T:53111    info <general>: Opening stream: 1003 source: 256
2023-06-12 16:29:55.161 T:53111    info <general>: Finding audio codec for: 86018
2023-06-12 16:29:55.162 T:53111    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2023-06-12 16:29:55.162 T:53111    info <general>: OpenStream: Allowing max Out-Of-Sync Value of 10 ms
2023-06-12 16:29:55.162 T:53111    info <general>: Creating audio thread
2023-06-12 16:29:55.163 T:53125    info <general>: running thread: CVideoPlayerAudio:rocess()
2023-06-12 16:29:55.163 T:53111    info <general>: AddOnLog: inputstream.adaptive: PosTime (90000000)
2023-06-12 16:29:55.175 T:53111    info <general>: Opening stream: 17001 source: 256
2023-06-12 16:29:55.194 T:53111    info <general>: Creating video codec with codec id: 27
2023-06-12 16:29:55.194 T:53111    info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2023-06-12 16:29:55.195 T:53111    info <general>: Opening stream: 17003 source: 256
2023-06-12 16:29:55.212 T:1562360    info <general>: EMBY.hooks.player: [ onAVChange ]
2023-06-12 16:29:55.217 T:53111    info <general>: Finding audio codec for: 86018
2023-06-12 16:29:55.218 T:53111    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2023-06-12 16:29:55.324 T:53111    info <general>: AddOnLog: inputstream.adaptive: Seek time 154.2 for stream: 17001 (physical index 65537) continues at 152.7 (PTS: 4608269098766)
2023-06-12 16:29:55.342 T:53111    info <general>: AddOnLog: inputstream.adaptive: Seek time 152.7 for stream: 17003 (physical index 131075) continues at 152.7 (PTS: 4608269098666)
2023-06-12 16:29:55.349 T:53140    info <general>: COutput::OnStartup: Output Thread created
2023-06-12 16:29:55.356 T:53125    info <general>: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through)
2023-06-12 16:29:55.356 T:1562345    info <general>: CActiveAE::ApplySettings - Forcing samplerate to 48000
2023-06-12 16:29:55.395 T:1562331    info <general>: GLES: Selecting single pass rendering
2023-06-12 16:29:55.395 T:1562331    info <general>: GLES: Selecting YUV 2 RGB shader
2023-06-12 16:29:55.396 T:1562331    info <general>: GLES: Selecting single pass rendering
2023-06-12 16:29:55.413 T:1562360    info <general>: Skipped 2 duplicate messages..
2023-06-12 16:29:55.413 T:1562360    info <general>: EMBY.hooks.player: [ onAVChange ]
2023-06-12 16:29:55.413 T:1562360    info <general>: Skipped 2 duplicate messages..
2023-06-12 16:29:55.413 T:1562360    info <general>: EMBY.hooks.player: [ onAVStarted ]
2023-06-12 16:29:55.414 T:1562360    info <general>: EMBY.database.dbio: ---> DBOpenRO: 61c7af3a7d61428d84f69a140f67fa1conAVStarted139657136289472
2023-06-12 16:29:55.415 T:1562360    info <general>: EMBY.database.dbio: ---< DBCloseRO: 61c7af3a7d61428d84f69a140f67fa1conAVStarted139657136289472
2023-06-12 16:29:55.515 T:1562360    info <general>: EMBY.hooks.player: [ onAVChange ]
2023-06-12 16:29:55.911 T:53122 warning <general>: OutputPicture - timeout waiting for buffer
2023-06-12 16:29:56.311 T:53122    info <general>: CDVDVideoCodecFFmpeg::CDropControl: calculated diff time: 16683
2023-06-12 16:29:59.315 T:53113   error <general>: AddOnLog: inputstream.adaptive: RefreshLiveSegments: Segment at position 0 not found from (update) representation id: EC3_1_CMAF_CENC_CTR_256K
2023-06-12 16:30:00.347 T:1562367    info <general>: [script.module.pvr.artwork] fetch data from cache: script.module.pvr.artwork.1.0.9.nba countdown
2023-06-12 16:30:00.404 T:1562367    info <general>: [script.module.pvr.artwork] no results in local databases
2023-06-12 16:30:00.849 T:1562367    info <general>: [script.module.pvr.artwork] scraping metadata from TMDB for title: texas vs. #8 stanford (game 3) ()
2023-06-12 16:30:04.051 T:53113   error <general>: AddOnLog: inputstream.adaptive: RefreshLiveSegments: Segment at position 0 not found from (update) representation id: EC3_1_CMAF_CENC_CTR_256K
2023-06-12 16:30:13.370 T:53125    info <general>: Skipped 4 duplicate messages..
2023-06-12 16:30:13.370 T:53125    info <general>: CVideoPlayerAudio:rocess - stream stalled
2023-06-12 16:30:14.432 T:55066   error <general>: AddOnLog: inputstream.adaptive: RefreshLiveSegments: Segment at position 0 not found from (update) representation id: EC3_1_CMAF_CENC_CTR_256K

Should I open an issue on the inputstream.adaptive github project with this log info?