Episode does not start playing

[demanu21]

So, first time user...

Not sure what the problem is, I read through the issues and could not find my "errors". I tried watching "de bunker", but problem occurs on any show (log is from "Clan").

My system:
Raspberry pi running buster (fully updated)
kodi v18.7
VTM.GO v1.2.6 (updated after running into #276)

extra info:
after updating the vtm.go plugin, I was informed there was an updated widevine, that upgrade succeeded (as far a I can tell).
In the error I see a complaint about "/home/pi/.kodi/cdm/libwidevinecdm.so" exists and is dated around time of upgrade.

The problem:
When I try to open a program, the spinning wheels show for a short time and then it returns to the episode list

The log (filtered on !NOTICE):

2021-05-08 10:43:24.939 T:895480032 ERROR: [script.module.inputstreamhelper] [u'ldd', u'/home/pi/.kodi/cdm/libwidevinecdm.so'] cmd failed.
2021-05-08 10:43:24.940 T:895480032 ERROR: [script.module.inputstreamhelper] Failed to check for missing Widevine libraries.

...

2021-05-08 10:43:27.582 T:895480032 ERROR: EXCEPTION: Invalid setting type

...

2021-05-08 10:43:27.993 T:1074774240 ERROR: 127.0.0.1 - - [08/May/2021 10:43:27] "GET /manifest?path=https%3A%2F%2Fdcs-vod.apis.anvato.net%2Fvod%2Fp%2Fsession%2Fmanifest.mpd%3Fi%3Di176423100-n14256c5d-3f75-4fdf-91ad-ee9acefc7494 HTTP/1.1" 200 -
2021-05-08 10:43:28.127 T:1013969120 ERROR: AddOnLog: InputStream Adaptive: Unable to load widevine shared library (/home/pi/.kodi/cdm/libwidevinecdm.so)
2021-05-08 10:43:28.128 T:1013969120 ERROR: AddOnLog: InputStream Adaptive: OpenDRMSystem failed
2021-05-08 10:43:28.130 T:1013969120 ERROR: CVideoPlayer::OpenInputStream - error opening [plugin://plugin.video.vtm.go/play/catalog/episodes/2536156f-7694-4573-8673-08a45195cf5d]

...

2021-05-08 10:43:28.648 T:895480032 WARNING: [plugin.video.vtm.go] [resources.lib.kodiplayer] Player: PlayBackStopped triggered while waiting for start.
2021-05-08 10:43:28.649 T:895480032 WARNING: Previous line repeats 6 times.
2021-05-08 10:43:28.649 T:895480032 WARNING: Attempt to use invalid handle 13
2021-05-08 10:43:28.793 T:1644142816 ERROR: EXCEPTION: XBMC is not playing any media file
2021-05-08 10:43:28.794 T:1644142816 ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
- NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
Error Type: <type 'exceptions.RuntimeError'>
Error Contents: XBMC is not playing any media file
Traceback (most recent call last):
File "/home/pi/.kodi/addons/service.autosubs/default.py", line 119, in onPlayBackStarted
totalTime = xbmc.Player().getTotalTime()
RuntimeError: XBMC is not playing any media file
-->End of Python script error report<--

[mediaminister]

Possible solution: Reboot Raspberry Pi

[demanu21]

Hi, just tried powercycling my pi. No luck.

[mediaminister]

I guess your problem is related to emilsvennesson/script.module.inputstreamhelper#413, please provide a full debug log there: https://kodi.wiki/view/Log_file/Easy

[demanu21]

Here it is: http://paste.kodi.tv/emedaqakoh

Let me read that possible related issue as well.

[mediaminister]

I need a log of the Widevine installation, removing the .kodi/cdm directory will trigger a new Widevine installation.

[demanu21]

second try: http://paste.kodi.tv/unafujuhih

I think you are interested starting at "2021-05-08 17:21:02.784 T:866119904" or thereabout...

[mediaminister]

Yes, this is a bug in InputStreamHelper, but I can't see all the info, you need to enable debug logging in Kodi Settings, so the log will contain more detailed info.

[demanu21]

I was wondering where all the DEBUG: tags were... Third try (after changing advancedsettings.xml): http://paste.kodi.tv/orofuvizid

I guess fun stuff starts at 2021-05-08 19:03:29.603 T:1760551136

Now that you are pretty sure that it is InputStreamHelper bug related: is there something I can do to make it working? I read #413, but I did not see a "solution" (apart from "downgrade", but I did not jump in that rabbit hole yet)

[mediaminister]

You can disable InputStreamHelper in the add-on settings and manually place the right libwidevinecdm.so in the .kodi/cdm directory.

[demanu21]

I got it working.

I found some backups of libwidevinecdm.so in /home/pi/.kodi/userdata/addon_data/script.module.inputstreamhelper/backup/, copied the previous version to ~/.kodi/cdm, done.

I did not disable InputStreamHelper (might bite me in the future, we'll see).

[mediaminister]

I have to correct my assumptions about InputStreamHelper, I guess it worked as intended.

But I compared your log with a log I made from LibreELEC and I found out that you are using an older InputStream Adaptive version:
2021-05-08 19:11:01.065 T:1760551136 DEBUG: [script.module.inputstreamhelper] inputstream.adaptive 2.4.4 is installed and enabled.
I guess that might be the problem:
2021-05-08 19:10:45.825 T:1308618976 ERROR: AddOnLog: InputStream Adaptive: Unable to load widevine shared library (/home/pi/.kodi/cdm/libwidevinecdm.so)

[mediaminister]

This is caused by a new libwidevinecdm library format, same error on Netflix add-on: CastagnaIT/plugin.video.netflix#1154

[demanu21]

indeed, I did exactly the same steps as mentioned here

If only I was brave enough to try that rollback option myself 'yesterday'...

[mediaminister]

This is very bad news for all Widevine protected content on Kodi, because older Widevine versions will stop working in the near future.