add-ons
Not all playback issues result in onPlayBackError callback
Describe the bug
In some cases it is possible for playback to fail without the add-on being able to report back to the user. The user will simply see a busy state followed by nothing because the add-on does not know playback has failed.
The normal flow is that Kodi or InputStream Adaptive performs an xbmc.Player.onPlayBackError callback so the add-on can handle it as expected (i.e. try an alternative playback method like use HLS instead of MPD, or provide a specific error to the user).
Here is an example of this problem:
2020-04-10 02:12:52.074 T:1378874240 NOTICE: [plugin.video.vrt.nu] Access: plugin://plugin.video.vrt.nu/play/id/vid-84618801-4e10-46a2-9403-d444fce53630/pbs-pub-0738b2b8-4242-4783-9686-8edb3f66be79
2020-04-10 02:12:52.106 T:1378874240 NOTICE: [plugin.video.vrt.nu] Got cached token '/storage/.kodi/userdata/addon_data/plugin.video.vrt.nu/tokens/ondemand_vrtPlayerToken.tkn'
2020-04-10 02:12:52.110 T:1378874240 NOTICE: [plugin.video.vrt.nu] URL get: https://media-services-public.vrt.be/vualto-video-aggregator-web/rest/external/v1/videos/pbs-pub-0738b2b8-4242-4783-9686-8edb3f66be79$vid-84618801-4e10-46a2-9403-d444fce53630?vrtPlayerToken=b10@e5af19407961d59b683f1b2c7384165485b11852a527bf030d3c1dd0f940cca3&client=vrtvideo@PROD
2020-04-10 02:12:52.487 T:1378874240 NOTICE: [plugin.video.vrt.nu] Protocol: mpeg_dash
2020-04-10 02:12:52.700 T:1378874240 NOTICE: [plugin.video.vrt.nu] Play: https://ondemand-cf.lwc.vrtcdn.be/content/vod/vid-84618801-4e10-46a2-9403-d444fce53630-CDN_5/vid-84618801-4e10-46a2-9403-d444fce53630-CDN_5_nodrm_90b2af9a-63cf-478e-b20b-46e7aec0c0cb.ism/.mpd
2020-04-10 02:12:52.730 T:1937706416 NOTICE: VideoPlayer::OpenFile: plugin://plugin.video.vrt.nu/play/id/vid-84618801-4e10-46a2-9403-d444fce53630/pbs-pub-0738b2b8-4242-4783-9686-8edb3f66be79
2020-04-10 02:12:52.736 T:1432351616 NOTICE: Creating InputStream
2020-04-10 02:12:52.761 T:1465889664 NOTICE: [plugin.video.vrt.nu] [PlayerInfo 9559] Event onPlayBackStarted
2020-04-10 02:12:52.764 T:1465889664 NOTICE: [plugin.video.vrt.nu] URL get: https://vrtnu-api.vrt.be/search?i=video&facets[videoId]=vid-84618801-4e10-46a2-9403-d444fce53630&size=1
2020-04-10 02:12:53.323 T:1432351616 ERROR: CCurlFile::FillBuffer - Failed: HTTP returned error 415
2020-04-10 02:12:53.323 T:1432351616 ERROR: CCurlFile::Open failed with code 415 for https://ondemand-cf.lwc.vrtcdn.be/content/vod/vid-84618801-4e10-46a2-9403-d444fce53630-CDN_5/vid-84618801-4e10-46a2-9403-d444fce53630-CDN_5_nodrm_90b2af9a-63cf-478e-b20b-46e7aec0c0cb.ism/.mpd:
2020-04-10 02:12:53.323 T:1432351616 ERROR: AddOnLog: InputStream Adaptive: Cannot download https://ondemand-cf.lwc.vrtcdn.be/content/vod/vid-84618801-4e10-46a2-9403-d444fce53630-CDN_5/vid-84618801-4e10-46a2-9403-d444fce53630-CDN_5_nodrm_90b2af9a-63cf-478e-b20b-46e7aec0c0cb.ism/.mpd
2020-04-10 02:12:53.323 T:1432351616 ERROR: AddOnLog: InputStream Adaptive: Could not open / parse mpdURL (https://ondemand-cf.lwc.vrtcdn.be/content/vod/vid-84618801-4e10-46a2-9403-d444fce53630-CDN_5/vid-84618801-4e10-46a2-9403-d444fce53630-CDN_5_nodrm_90b2af9a-63cf-478e-b20b-46e7aec0c0cb.ism/.mpd)
2020-04-10 02:12:53.324 T:1432351616 ERROR: CVideoPlayer::OpenInputStream - error opening [plugin://plugin.video.vrt.nu/play/id/vid-84618801-4e10-46a2-9403-d444fce53630/pbs-pub-0738b2b8-4242-4783-9686-8edb3f66be79]
2020-04-10 02:12:53.324 T:1432351616 NOTICE: CVideoPlayer::OnExit()
2020-04-10 02:12:53.382 T:1937706416 NOTICE: CVideoPlayer::CloseFile()
2020-04-10 02:12:53.383 T:1937706416 NOTICE: VideoPlayer: waiting for threads to exit
2020-04-10 02:12:53.383 T:1937706416 NOTICE: VideoPlayer: finished waiting
2020-04-10 02:12:53.403 T:1465889664 NOTICE: [plugin.video.vrt.nu] [PlayerInfo 9559] Event onPlayBackStopped
IIRC this also happens on Widevine playback issues where inputstreamhelper cannot offer to install the Widevine library when playback fails because we do not know. If we did (e.g. through onPlayBackError) we would not have to check everything beforehand everytime. See emilsvennesson/script.module.inputstreamhelper#69
This relates to: #307
To Reproduce
Steps to reproduce the behavior:
- Make it fail in a specific way :-)
Expected behavior
We should get an xbmc.Player.onPlayBackError call.
Additional context
- Operating system: LibreELEC v9.2.1
- Kodi version: 18.6
- Addon version: 2.3.2
- Using a VPN: no
- Country you are using the addon from: BE
Below is an example where an update of inputstream.adaptive causes playback issues until Kodi has been restarted. It would be very useful if the add-on would get an onPlayBackError call so we can advise the user to restart Kodi, rather than failing to playback and returning to the menu.
Everytime there is an inputstream.adaptive update we have users that report issues with the add-on or with Kodi (and do not know they have to restart Kodi, or even were aware IA was updated).
2020-04-11 03:25:32.763 T:1305469824 NOTICE: [plugin.video.vrt.nu] Access: plugin://plugin.video.vrt.nu/play/id/vid-335d7118-7eff-4fd7-a9be-670ee4495f5a/pbs-pub-68f789d5-b834-4dd7-aac9-f1ec6ee8bbfe
2020-04-11 03:25:32.780 T:1305469824 NOTICE: [plugin.video.vrt.nu] Got cached token '/storage/.kodi/userdata/addon_data/plugin.video.vrt.nu/tokens/ondemand_vrtPlayerToken.tkn'
2020-04-11 03:25:32.782 T:1305469824 NOTICE: [plugin.video.vrt.nu] URL get: https://media-services-public.vrt.be/vualto-video-aggregator-web/rest/external/v1/videos/pbs-pub-68f789d5-b834-4dd7-aac9-f1ec6ee8bbfe$vid-335d7118-7eff-4fd7-a9be-670ee4495f5a?vrtPlayerToken=b10@c8c32f84935f37963598f5ba212ff62e68b8545c06ca0e37a6e9ad92f5325386&client=vrtvideo@PROD
2020-04-11 03:25:33.059 T:1305469824 NOTICE: [plugin.video.vrt.nu] Protocol: mpeg_dash
2020-04-11 03:25:33.280 T:1305469824 NOTICE: [plugin.video.vrt.nu] Play: https://ondemand-cf.lwc.vrtcdn.be/content/vod/vid-335d7118-7eff-4fd7-a9be-670ee4495f5a-CDN_2/vid-335d7118-7eff-4fd7-a9be-670ee4495f5a-CDN_2_nodrm_921b80ed-1e29-4d73-9925-4b39dd00b9dc.ism/.mpd
2020-04-11 03:25:33.312 T:1937093184 NOTICE: VideoPlayer::OpenFile: plugin://plugin.video.vrt.nu/play/id/vid-335d7118-7eff-4fd7-a9be-670ee4495f5a/pbs-pub-68f789d5-b834-4dd7-aac9-f1ec6ee8bbfe
2020-04-11 03:25:33.314 T:1205859200 NOTICE: Creating InputStream
2020-04-11 03:25:33.315 T:1205859200 ERROR: ADDON: Could not locate inputstream.adaptive.so.2.4.3
2020-04-11 03:25:33.316 T:1205859200 ERROR: IAddonInstanceHandler::CreateInstance: inputstream.adaptive returned bad status "Permanent failure" during instance creation
2020-04-11 03:25:33.316 T:1205859200 ERROR: CVideoPlayer::OpenInputStream - error opening [plugin://plugin.video.vrt.nu/play/id/vid-335d7118-7eff-4fd7-a9be-670ee4495f5a/pbs-pub-68f789d5-b834-4dd7-aac9-f1ec6ee8bbfe]
2020-04-11 03:25:33.316 T:1205859200 NOTICE: CVideoPlayer::OnExit()
2020-04-11 03:25:33.424 T:1563464576 NOTICE: [plugin.video.vrt.nu] [PlayerInfo 2060] Event onPlayBackStarted
2020-04-11 03:25:33.425 T:1563464576 NOTICE: [plugin.video.vrt.nu] URL get: https://vrtnu-api.vrt.be/search?i=video&facets[videoId]=vid-335d7118-7eff-4fd7-a9be-670ee4495f5a&size=1
2020-04-11 03:25:33.528 T:1937093184 NOTICE: CVideoPlayer::CloseFile()
2020-04-11 03:25:33.529 T:1937093184 NOTICE: VideoPlayer: waiting for threads to exit
2020-04-11 03:25:33.529 T:1937093184 NOTICE: VideoPlayer: finished waiting
2020-04-11 03:25:38.505 T:1563464576 NOTICE: [plugin.video.vrt.nu] [PlayerInfo 2060] Event onPlayBackStopped
What is worse, Kodi even calls onPlayBackStarted and onPlayBackStopped after inputstream.adaptive already has failed.
cc @peak3d
@peak3d I was planning to open an issue upstream, but was not sure whether the cause here is IA or Kodi. Let me know where to open a proper issue with full debug log. :+1: