Timeout: The read operation timed out

[dagwieers]

Describe the bug

It appears we are having these read timeouts quite often lately. It is unclear to me what is causing them, but maybe this is an opportunity to make our code somewhat more robust when this happens.

To Reproduce

Not sure how to reproduce it, we get it quite a lot since very recently.

Expected behavior

We now get a generic Kodi plugin error, whereas I would rather have it show there are issues with the connection, and include the Timeout error "The read operation timed out" as part of it.

Additional context

• Operating system: LibreELEC v10.0.1
• Kodi version: v19.3
• Addon version: v2.5.7+matrix.1 (with A read timeout (socket.timeout) causes exception #936 included)
• Using a VPN: no
• Country you are using the addon from: BE

Log (if available)

2022-02-18 23:35:23.087 T:14086    INFO <general>: initializing python engine.
2022-02-18 23:35:23.367 T:14086 WARNING <general>: [plugin.video.vrt.nu] Access: plugin://plugin.video.vrt.nu/
2022-02-18 23:35:23.393 T:14086    INFO <general>: CPythonInvoker(170, /storage/.kodi/addons/plugin.video.vrt.nu/resources/lib/addon_entry.py): script successfully run
2022-02-18 23:35:36.436 T:14086    INFO <general>: initializing python engine.
2022-02-18 23:35:36.448 T:14086 WARNING <general>: [plugin.video.vrt.nu] Access: plugin://plugin.video.vrt.nu/favorites
2022-02-18 23:35:36.556 T:14086 WARNING <general>: [plugin.video.vrt.nu] Got item from cache '/storage/.kodi/userdata/addon_data/plugin.video.vrt.nu/tokens/vrtloginat.tkn'
2022-02-18 23:35:36.564 T:14086 WARNING <general>: [plugin.video.vrt.nu] URL get: https://www.vrt.be/vrtnu-api/rest/lists/vrtnu-favoritePrograms?tileType=program-poster&tileContentType=program&tileOrientation=po
rtrait&layout=slider&title=Mijn+favoriete+programma's
2022-02-18 23:35:39.311 T:14086   FATAL <general>: [plugin.video.vrt.nu] Timeout: The read operation timed out
                                                   url: https://www.vrt.be/vrtnu-api/rest/lists/vrtnu-favoritePrograms?tileType=program-poster&tileContentType=program&tileOrientation=portrait&layout=slider&title=Mijn+favoriete+programma%27s
2022-02-18 23:35:39.326 T:14086   ERROR <general>: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                                    - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                                   Error Type: <class 'AttributeError'>
                                                   Error Contents: 'NoneType' object has no attribute 'get'
                                                   Traceback (most recent call last):
                                                     File "/storage/.kodi/addons/plugin.video.vrt.nu/resources/lib/addon_entry.py", line 14, in<module>
                                                       run(argv)
                                                     File "/storage/.kodi/addons/plugin.video.vrt.nu/resources/lib/addon.py", line 362, in run
                                                       plugin.run(argv)
                                                     File "/storage/.kodi/addons/script.module.routing/lib/routing.py", line 130, in run
                                                       self._dispatch(self.path)
                                                     File "/storage/.kodi/addons/script.module.routing/lib/routing.py", line 141, in _dispatch
                                                       view_func(**kwargs)
                                                     File "/storage/.kodi/addons/plugin.video.vrt.nu/resources/lib/addon.py", line 81, in favorites_menu
                                                       VRTPlayer().show_favorites_menu()
                                                     File "/storage/.kodi/addons/plugin.video.vrt.nu/resources/lib/vrtplayer.py", line 125, in show_favorites_menu
                                                       self._favorites.refresh(ttl=ttl('indirect'))
                                                     File "/storage/.kodi/addons/plugin.video.vrt.nu/resources/lib/favorites.py", line 40, in refresh
                                                       favorites_dict = self._generate_favorites_dict(self.get_favorites())
                                                     File "/storage/.kodi/addons/plugin.video.vrt.nu/resources/lib/favorites.py", line 184, in _generate_favorites_dict
                                                       for item in favorites_json.get(':items', []):
                                                   AttributeError: 'NoneType' object has no attribute 'get'
                                                   -->End of Python script error report<--
                                                   
2022-02-18 23:35:40.018 T:14086    INFO <general>: Python interpreter stopped
2022-02-18 23:35:40.031 T:14090    INFO <general>: Skipped 1 duplicate messages..
2022-02-18 23:35:40.031 T:14090   ERROR <general>: GetDirectory - Error getting plugin://plugin.video.vrt.nu/favorites
2022-02-18 23:35:40.035 T:16370   ERROR <general>: CGUIMediaWindow::GetDirectory(plugin://plugin.video.vrt.nu/favorites) failed

[dagwieers]

After experiencing this once more (with fix #936) you get the standard error box pointing at a possible network issue. What is strange here is that if I try it a few more times it actually gets past the error fine. It is as if the device has network issues when being idle for some time and the first network-related activity gets a read-timeout. I have only seen this with the VRT NU add-on, but that is no surprise since it is the one I am using the most, and usually the first.

So looking at what is going on, I think we cannot improve it any further, except maybe the following three ideas:

• Display the actual error message (in this case: "Timeout: The read operation timed out") so that the user has something to work with (or relate to recurring issues)
• We may want to hint to try it again, since it could be a temporary error (which it is in my case)
• Possibly retry the read/download a few times, before giving up (if we could identify what is causing it, we could even test for it)

Also, what surprises me is that I get the Timeout error almost instantly, whereas you would expect to get a Timeout error after some noticeable period of time has passed, so this might be something to investigate as well. Maybe something that can be tweaked from our side ?

[michaelarnauts]

Since you get the time-out almost instantly, I'm thinking about a too low timeout value in the code somewhere, like a value in ms instead of seconds or something?

[mediaminister]

I'll take a look, since version 2.5.7 a new favorites api is used. VRT deprecated the previous one
It seems this new api doesn't always return the favorites data that is requested.
The data is requested with get_url_json from kodiutils just like we did before. It guess it's just this new api that behaves differently.