Kodi binding exception when starting PVR recording

@pail_frank23

Any idea what causes this exception?

2017-08-27 23:19:29.371 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Kveldsnytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
java.lang.NullPointerException: null
        at org.openhab.binding.kodi.internal.protocol.KodiConnection.requestPlayerUpdate(KodiConnection.java:234) [184:org.openhab.binding.kodi:2.2.0.201708201100]
        at org.openhab.binding.kodi.internal.protocol.KodiConnection.processPlayerStateChanged(KodiConnection.java:377) [184:org.openhab.binding.kodi:2.2.0.201708201100]
        at org.openhab.binding.kodi.internal.protocol.KodiConnection.handleEvent(KodiConnection.java:354) [184:org.openhab.binding.kodi:2.2.0.201708201100]
        at org.openhab.binding.kodi.internal.protocol.KodiClientSocket$KodiWebSocketListener$2.run(KodiClientSocket.java:158) [184:org.openhab.binding.kodi:2.2.0.201708201100]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

I’m running Kodi 17.2 and my PVR TV backend is DVBlogic.

Hi Ole,

could you be so kind and activate DEBUG logging and post a complete abstract of your log file? I guess we can handle this NPE. Thanks.

Here is the log from just before starting a PVR playback.
No NPE when stopped, but it is not happening every time.
Have a ‘feeling’ it happens more often after a longer period of idle when starting playing, or after a longer period of playing when stopping.
When the NPE happens, the item { channel = “kodi:kodi:285515eb-b31c-7cf4-7b87-a19928548675:stop” } sometimes ends up in the wrong state. (Says Stopped==ON while playing)

Thank you for looking into this.
Cheers

openhab> bundle:list | grep -i kodi
184 â Active   â  80 â 2.2.0.201708201100     â Kodi Binding


2017-08-28 22:11:04.969 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3005,"method":"Application.GetProperties","params":{"properties":["version","name"]}}
2017-08-28 22:11:04.971 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3005,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:04.972 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3005,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:04.973 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3005,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:14.973 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3006,"method":"Application.GetProperties","params":{"properties":["version","name"]}}
2017-08-28 22:11:14.974 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3006,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:14.975 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3006,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:14.975 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3006,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:17.518 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"jsonrpc":"2.0","method":"GUI.OnScreensaverDeactivated","params":{"data":{"shuttingdown":false},"sender":"xbmc"}}
2017-08-28 22:11:17.518 [DEBUG] [i.internal.protocol.KodiClientSocket] - Event received from server: {"jsonrpc":"2.0","method":"GUI.OnScreensaverDeactivated","params":{"data":{"shuttingdown":false},"sender":"xbmc"}}
2017-08-28 22:11:17.520 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3007,"method":"Application.GetProperties","params":{"properties":["version","name"]}}
2017-08-28 22:11:17.521 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3007,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:17.522 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3007,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:17.522 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3007,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:24.976 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3008,"method":"Application.GetProperties","params":{"properties":["version","name"]}}
2017-08-28 22:11:24.977 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3008,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:24.977 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3008,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:24.978 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3008,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:28.089 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen 21","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}}
2017-08-28 22:11:28.089 [DEBUG] [i.internal.protocol.KodiClientSocket] - Event received from server: {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen 21","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}}
2017-08-28 22:11:28.099 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3009,"method":"Player.GetItem","params":{"playerid":-1,"properties":["title","album","artist","director","thumbnail","file","fanart","showtitle","streamdetails","channel","channeltype"]}}
2017-08-28 22:11:28.100 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"error":{"code":-32602,"data":{"method":"Player.GetItem","stack":{"message":"Value between 0 (inclusive) and 2 (inclusive) expected but -1 received","name":"playerid","type":"integer"}},"message":"Invalid params."},"id":3009,"jsonrpc":"2.0"}
2017-08-28 22:11:28.101 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"error":{"code":-32602,"data":{"method":"Player.GetItem","stack":{"message":"Value between 0 (inclusive) and 2 (inclusive) expected but -1 received","name":"playerid","type":"integer"}},"message":"Invalid params."},"id":3009,"jsonrpc":"2.0"}
2017-08-28 22:11:28.102 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"error":{"code":-32602,"data":{"method":"Player.GetItem","stack":{"message":"Value between 0 (inclusive) and 2 (inclusive) expected but -1 received","name":"playerid","type":"integer"}},"message":"Invalid params."},"id":3009,"jsonrpc":"2.0"}
2017-08-28 22:11:28.104 [INFO ] [.eclipse.smarthome.model.script.Kodi] - KodiStopped.state=OFF
2017-08-28 22:11:28.106 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen 21","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
java.lang.NullPointerException: null
        at org.openhab.binding.kodi.internal.protocol.KodiConnection.requestPlayerUpdate(KodiConnection.java:234) [184:org.openhab.binding.kodi:2.2.0.201708201100]
        at org.openhab.binding.kodi.internal.protocol.KodiConnection.processPlayerStateChanged(KodiConnection.java:377) [184:org.openhab.binding.kodi:2.2.0.201708201100]
        at org.openhab.binding.kodi.internal.protocol.KodiConnection.handleEvent(KodiConnection.java:354) [184:org.openhab.binding.kodi:2.2.0.201708201100]
        at org.openhab.binding.kodi.internal.protocol.KodiClientSocket$KodiWebSocketListener$2.run(KodiClientSocket.java:158) [184:org.openhab.binding.kodi:2.2.0.201708201100]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2017-08-28 22:11:34.538 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3010,"method":"Player.GetActivePlayers"}
2017-08-28 22:11:34.539 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3010,"jsonrpc":"2.0","result":[{"playerid":1,"type":"video"}]}
2017-08-28 22:11:34.540 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3010,"jsonrpc":"2.0","result":[{"playerid":1,"type":"video"}]}
2017-08-28 22:11:34.540 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3010,"jsonrpc":"2.0","result":[{"playerid":1,"type":"video"}]}
2017-08-28 22:11:34.541 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3011,"method":"Player.GetProperties","params":{"playerid":1,"properties":["speed","position"]}}
2017-08-28 22:11:34.542 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3011,"jsonrpc":"2.0","result":{"position":-1,"speed":1}}
2017-08-28 22:11:34.542 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3011,"jsonrpc":"2.0","result":{"position":-1,"speed":1}}
2017-08-28 22:11:34.543 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3011,"jsonrpc":"2.0","result":{"position":-1,"speed":1}}
2017-08-28 22:11:34.552 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3012,"method":"Player.GetItem","params":{"playerid":1,"properties":["title","album","artist","director","thumbnail","file","fanart","showtitle","streamdetails","channel","channeltype"]}}
2017-08-28 22:11:34.559 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3012,"jsonrpc":"2.0","result":{"item":{"album":"","artist":[],"channel":"NRK1","director":[],"fanart":"","file":"pvr://recordings/tv/active/Dagsrevyen 21/Dagsrevyen%2021, TV%20(NRK1), 20170828_190004, 7e193489-2e9a-4e67-99c9-b3ada3dd6a34:F6F08949-2A07-4074-9E9D-423D877270BB/3-19170000-1503946800.pvr","id":4719,"label":"Dagsrevyen 21","showtitle":"","streamdetails":{"audio":[],"subtitle":[],"video":[]},"thumbnail":"image://http%3a%2f%2f127.0.0.1%3a8101%2fdvblink%2fplayback%3fobject%3d7e193489-2e9a-4e67-99c9-b3ada3dd6a34%253aDA5F661E-540E-47B1-9DCC-3F40F5CB85CA%252f3-19170000-1503946800/","title":"Dagsrevyen 21","type":"unknown"}}}
2017-08-28 22:11:34.559 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3012,"jsonrpc":"2.0","result":{"item":{"album":"","artist":[],"channel":"NRK1","director":[],"fanart":"","file":"pvr://recordings/tv/active/Dagsrevyen 21/Dagsrevyen%2021, TV%20(NRK1), 20170828_190004, 7e193489-2e9a-4e67-99c9-b3ada3dd6a34:F6F08949-2A07-4074-9E9D-423D877270BB/3-19170000-1503946800.pvr","id":4719,"label":"Dagsrevyen 21","showtitle":"","streamdetails":{"audio":[],"subtitle":[],"video":[]},"thumbnail":"image://http%3a%2f%2f127.0.0.1%3a8101%2fdvblink%2fplayback%3fobject%3d7e193489-2e9a-4e67-99c9-b3ada3dd6a34%253aDA5F661E-540E-47B1-9DCC-3F40F5CB85CA%252f3-19170000-1503946800/","title":"Dagsrevyen 21","type":"unknown"}}}
2017-08-28 22:11:34.560 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3012,"jsonrpc":"2.0","result":{"item":{"album":"","artist":[],"channel":"NRK1","director":[],"fanart":"","file":"pvr://recordings/tv/active/Dagsrevyen 21/Dagsrevyen%2021, TV%20(NRK1), 20170828_190004, 7e193489-2e9a-4e67-99c9-b3ada3dd6a34:F6F08949-2A07-4074-9E9D-423D877270BB/3-19170000-1503946800.pvr","id":4719,"label":"Dagsrevyen 21","showtitle":"","streamdetails":{"audio":[],"subtitle":[],"video":[]},"thumbnail":"image://http%3a%2f%2f127.0.0.1%3a8101%2fdvblink%2fplayback%3fobject%3d7e193489-2e9a-4e67-99c9-b3ada3dd6a34%253aDA5F661E-540E-47B1-9DCC-3F40F5CB85CA%252f3-19170000-1503946800/","title":"Dagsrevyen 21","type":"unknown"}}}
2017-08-28 22:11:34.978 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3013,"method":"Application.GetProperties","params":{"properties":["version","name"]}}
2017-08-28 22:11:34.979 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3013,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:34.980 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3013,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:34.980 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3013,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":3,"revision":"20170524-147cec4","tag":"stable"}}}
2017-08-28 22:11:44.579 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3014,"method":"Player.GetActivePlayers"}
2017-08-28 22:11:44.580 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3014,"jsonrpc":"2.0","result":[{"playerid":1,"type":"video"}]}
2017-08-28 22:11:44.581 [DEBUG] [i.internal.protocol.KodiClientSocket] - Response received from server: {"id":3014,"jsonrpc":"2.0","result":[{"playerid":1,"type":"video"}]}
2017-08-28 22:11:44.582 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":3014,"jsonrpc":"2.0","result":[{"playerid":1,"type":"video"}]}
2017-08-28 22:11:44.582 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":3015,"method":"Player.GetProperties","params":{"playerid":1,"properties":["speed","position"]}}
2017-08-28 22:11:44.583 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":3015,"jsonrpc":"2.0","result":{"position":-1,"speed":1}}

Here is the NPE collection since the 15th:

omr@shs2:~$ grep -i 'Error handling' /var/log/openhab2/openhab.log 
2017-08-15 10:06:30.481 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":2,"season":6,"showtitle":"Game of Thrones","title":"Home","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 10:38:56.717 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":2,"season":6,"showtitle":"Game of Thrones","title":"Home","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 11:12:41.941 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":3,"season":6,"showtitle":"Game of Thrones","title":"Oathbreaker","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 11:58:57.493 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":3,"season":6,"showtitle":"Game of Thrones","title":"Oathbreaker","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 12:24:44.434 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":4,"season":6,"showtitle":"Game of Thrones","title":"Book of the Stranger","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 12:43:23.373 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":4,"season":6,"showtitle":"Game of Thrones","title":"Book of the Stranger","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 12:47:37.900 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":4,"season":6,"showtitle":"Game of Thrones","title":"Book of the Stranger","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 14:07:06.347 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":4,"season":6,"showtitle":"Game of Thrones","title":"Book of the Stranger","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 14:07:38.630 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":5,"season":6,"showtitle":"Game of Thrones","title":"The Door","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-15 20:46:24.420 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-16 10:52:09.739 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":6,"season":6,"showtitle":"Game of Thrones","title":"Blood of My Blood","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-16 11:15:30.505 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":6,"season":6,"showtitle":"Game of Thrones","title":"Blood of My Blood","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-16 11:30:10.932 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":6,"season":6,"showtitle":"Game of Thrones","title":"Blood of My Blood","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-16 11:47:33.207 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":7,"season":6,"showtitle":"Game of Thrones","title":"The Broken Man","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-16 11:59:58.996 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":7,"season":6,"showtitle":"Game of Thrones","title":"The Broken Man","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-16 12:41:40.167 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":7,"season":6,"showtitle":"Game of Thrones","title":"The Broken Man","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-16 20:15:18.743 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-16 20:45:23.357 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-17 13:43:41.965 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":7,"season":6,"showtitle":"Game of Thrones","title":"The Broken Man","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-17 13:44:32.285 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":8,"season":6,"showtitle":"Game of Thrones","title":"No One","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-17 13:53:25.390 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":8,"season":6,"showtitle":"Game of Thrones","title":"No One","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-17 14:49:42.564 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":8,"season":6,"showtitle":"Game of Thrones","title":"No One","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-17 14:53:32.577 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":9,"season":6,"showtitle":"Game of Thrones","title":"Battle of the Bastards","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-17 15:56:34.802 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"episode":10,"season":6,"showtitle":"Game of Thrones","title":"The Winds of Winter","type":"episode"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-18 17:01:56.272 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"PÃ¥ vei til","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-18 17:02:14.912 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"PÃ¥ vei til","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-18 17:02:20.426 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"PÃ¥ vei til","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-20 19:50:45.922 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-21 20:30:09.784 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-21 20:31:03.667 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-21 23:26:57.613 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Kveldsnytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-22 19:23:59.257 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-23 19:24:46.323 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-23 19:49:45.092 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-25 21:28:30.160 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-27 00:21:06.134 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Kveldsnytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-27 09:33:40.435 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Linn & Ronnys tacoshow","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-27 15:39:38.663 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Lindmo","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-27 23:19:29.371 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Kveldsnytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-28 20:42:28.950 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Nytt på nytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-28 20:46:37.283 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Nytt på nytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-28 21:04:13.576 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Nytt på nytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-28 21:13:32.455 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Nytt på nytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-28 21:14:37.394 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Nytt på nytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-28 21:15:31.336 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Nytt på nytt","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
2017-08-28 22:11:28.106 [ERROR] [i.internal.protocol.KodiClientSocket] - Error handling event {"jsonrpc":"2.0","method":"Player.OnPlay","params":{"data":{"item":{"title":"Dagsrevyen 21","type":"movie"},"player":{"playerid":-1,"speed":1}},"sender":"xbmc"}} player state change message: null
omr@shs2:~$

Thank you very much. It looks like we need some hardening for the error handling in Kodi connection implementation.

You are on snapshot #1020?

Opened an issue:

Yep:
omr@shs2:~$ ssh openhab@localhost -p 8101
Password authentication
Password:

                          __  _____    ____      
  ____  ____  ___  ____  / / / /   |  / __ )     
 / __ \/ __ \/ _ \/ __ \/ /_/ / /| | / __  | 
/ /_/ / /_/ /  __/ / / / __  / ___ |/ /_/ /      
\____/ .___/\___/_/ /_/_/ /_/_/  |_/_____/     
    /_/                        2.2.0-SNAPSHOT
                               Build #1020   

Hit '<tab>' for a list of available commands

Fix is on the road:

Nice! I’ll take it for a spin in a few days when the OH2.2.0#1025+ waves settles.
Will report back then.

Fix is merged. Will be part in an upcoming snapshot.

Have tried Snapshot #1031 for a few days now, and no NPEs spotted :slight_smile:
Good work!

Only one issue left for me now.

Sounds good. It’s a pleasure.