[PROBLEM] Kodi randomly hangs while playing audio

[jakenl]

As of a couple weeks ago Kodi starts to randomly hang while playing audio. Afterwards Kodi (GUI) is completely unresponsive. Even a restart of the service by 'sudo service xbmc restart' takes an awful long time and doesn't result in a working Kodi afterwards. My only solution is a reboot.

I checked out the running mp3 file, but nex time Kodi doesn't have issues playing it. Therefore I enabled debug logging to see if I can catch any additional information, leading to the error. I have added the log from the line where the last just started playing correctly. In the middle of that file Kodi quit on me.

last bit of log file (Click to View)

2020-02-16 12:17:06.308 T:2955410800 DEBUG: unrecognized ID3 frame detected: MCDI
2020-02-16 12:17:06.308 T:2955410800 DEBUG: unrecognized ID3 frame detected: PRIV
2020-02-16 12:17:06.308 T:2955410800 DEBUG: unrecognized ID3 frame detected: TLEN
2020-02-16 12:17:06.309 T:2955410800 DEBUG: CPlayerGUIInfo::InitCurrentItem(musicdb://songs/2793.mp3)
2020-02-16 12:17:06.324 T:2741100768 DEBUG: XBian XBMC-Upstart bridge: got notification for event Player.OnPlay. player.isPlayingLiveTV() = False
2020-02-16 12:17:06.325 T:2741100768 DEBUG: XBian XBMC-Upstart bridge: emitting Upstart event: sudo initctl emit -n -q player ACTION=PLAY TYPE=SONG
2020-02-16 12:17:06.372 T:2924474592 DEBUG: CActiveAE::DiscardStream - audio stream deleted
2020-02-16 12:17:06.373 T:2565837024 DEBUG: DoWork - Saving file state for audio item musicdb://songs/2792.mp3
2020-02-16 12:17:06.373 T:2924474592 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
2020-02-16 12:17:06.374 T:2515529952 DEBUG: Previous line repeats 1 times.
2020-02-16 12:17:06.374 T:2515529952 DEBUG: PAPlayer::ProcessStreams - Stream Freed
2020-02-16 12:17:06.404 T:2565837024 DEBUG: DoWork - Marking audio item musicdb://songs/2792.mp3 as listened
2020-02-16 12:17:06.410 T:2955410800 DEBUG: ------ Window Init (DialogBusy.xml) ------
2020-02-16 12:17:06.411 T:2955410800 DEBUG: Window DialogBusy.xml was already loaded
2020-02-16 12:17:06.411 T:2955410800 DEBUG: Alloc resources: 0.12ms
2020-02-16 12:17:06.509 T:2741100768 DEBUG: XBian XBMC-Upstart bridge: calculated priority: 2, based on monitor.screensaver=True, monitor.library_statuses={'scanning_video': False, 'cleaning_video': False, 'scanning_music': False, 'cleaning_music': False}, player.isPlaying()=1, player.isPlayingLiveTV()=False
2020-02-16 12:17:06.528 T:2955410800 DEBUG: ------ Window Deinit (DialogBusy.xml) ------
2020-02-16 12:17:06.528 T:2955410800 WARNING: OnMessage: Suspiciously long time to handle GUI_MSG_PLAYBACK_STARTED (0.27s)
2020-02-16 12:17:06.571 T:2924474592 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
2020-02-16 12:17:36.429 T:2565837024 DEBUG: Thread JobWorker 2565837024 terminating (autodelete)
2020-02-16 12:18:55.680 T:2678046944 DEBUG: JSONRPC Server: New connection detected
2020-02-16 12:18:55.680 T:2678046944 INFO: JSONRPC Server: New connection added
2020-02-16 12:18:55.683 T:2565837024 DEBUG: CWebServer[8080]: request received for /jsonrpc
2020-02-16 12:19:02.917 T:2686439648 DEBUG: Previous line repeats 24 times.
2020-02-16 12:19:02.917 T:2686439648 DEBUG: EventClient: button code 0 pressed
2020-02-16 12:19:02.922 T:2955410800 DEBUG: HandleKey: sleep (0xdf) pressed, screen saver/dpms woken up
2020-02-16 12:19:02.959 T:2749493472 DEBUG: XBian-config : on saver deactivated
2020-02-16 12:19:03.258 T:2741100768 DEBUG: XBian XBMC-Upstart bridge: got notification for event onScreensaverDeactivated
2020-02-16 12:19:03.259 T:2741100768 DEBUG: XBian XBMC-Upstart bridge: emitting Upstart event: sudo initctl emit -n -q screensaver ACTION=STOP
2020-02-16 12:19:03.482 T:2741100768 DEBUG: XBian XBMC-Upstart bridge: calculated priority: 4, based on monitor.screensaver=False, monitor.library_statuses={'scanning_video': False, 'cleaning_video': False, 'scanning_music': False, 'cleaning_music': False}, player.isPlaying()=1, player.isPlayingLiveTV()=False
2020-02-16 12:19:03.482 T:2741100768 DEBUG: XBian XBMC-Upstart bridge: emitting Upstart event: sudo initctl emit -n -q xbmcplevel PREVLEVEL=2 LEVEL=4
2020-02-16 12:19:03.937 T:2565837024 DEBUG: CWebServer[8080]: request received for /jsonrpc
2020-02-16 12:19:03.943 T:2955410800 DEBUG: ------ Window Deinit () ------
2020-02-16 12:19:03.948 T:2565837024 DEBUG: CWebServer[8080]: request received for /jsonrpc
2020-02-16 12:19:06.071 T:2686439648 DEBUG: Previous line repeats 8 times.
2020-02-16 12:19:06.071 T:2686439648 DEBUG: EventClient: button code 0 pressed
2020-02-16 12:19:06.075 T:2955410800 DEBUG: HandleKey: sleep (0xdf) pressed, action is SkipNext
2020-02-16 12:19:06.075 T:2955410800 DEBUG: CPlayerCoreFactory::GetPlayers(musicdb://songs/2794.mp3)
2020-02-16 12:19:06.075 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: mms/udp
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerCoreFactory::GetPlayers: adding audiodefaultplayer (PAPlayer)
2020-02-16 12:19:06.076 T:2955410800 DEBUG: CPlayerCoreFactory::GetPlayers: for video=0, audio=1
2020-02-16 12:19:06.077 T:2955410800 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
2020-02-16 12:19:06.077 T:2955410800 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: VideoPlayer
2020-02-16 12:19:06.077 T:2955410800 DEBUG: CPlayerCoreFactory::GetPlayers: added 2 players
2020-02-16 12:19:07.179 T:2565837024 DEBUG: CWebServer[8080]: request received for /jsonrpc
2020-02-16 12:19:07.278 T:2686439648 DEBUG: Previous line repeats 4 times.
2020-02-16 12:19:07.278 T:2686439648 DEBUG: EventClient: button code 0 pressed
2020-02-16 12:19:08.255 T:2582622432 DEBUG: CWebServer[8080]: request received for /jsonrpc
2020-02-16 12:19:16.639 T:2678046944 DEBUG: Previous line repeats 2 times.
2020-02-16 12:19:16.639 T:2678046944 INFO: JSONRPC Server: Disconnection detected
2020-02-16 12:20:08.338 T:2686439648 NOTICE: ES: Client from 192.168.1.4 timed out

After such a crash the SSH connection is still responsive, but as soon as I force a 'sudo reboot' the RPI disappears from the network and doesn't come alive anymore, unless I physically pull the plug.