Repeatable Kodi crash after about 1 hour (JSONRPC Server: Accept of new connection failed: 24)

Help and Support Raspberry Pi
1

Hi Everyone,

I am fighting since a week with a weird behave of OSMC Kodi 17.6 Dec release, now on my RPI3.
I switched my Setup from RPI2 to RPI3 and on RPI2 same configuration is still running fine.

Running OSMC for about 1 hour works fine and then Kodie restarted, very often with last messages like:

14:11:59.226 T:994046720   ERROR: Unable to open database: MyVideos107 [2004](Can't create TCP/IP socket (24 "Too many open files"))
14:12:06.293 T:1370501888   ERROR: Previous line repeats 61 times.
14:12:06.293 T:1370501888   ERROR: JSONRPC Server: Accept of new connection failed: 24

Or very similar messages, always related to JSONRPC Server: Accept of new connection failed: 24.

Disabling all Addons etc does not change anything in the behave. Even a couple for fresh installations and using everything in a default setup does not help at all. And from time to time, the same system runs fine for hours !

The system, see logs, runs from 13:07 to about 14:12 o clock. Based on the logs I always find something like:

Jan 23 14:12:25 HORST kernel: Out of memory: Kill process 571 (kodi.bin) score 879 or sacrifice child
Jan 23 14:12:25 HORST kernel: Killed process 571 (kodi.bin) total-vm:1460116kB, anon-rss:671188kB, file-rss:532kB, shmem-rss:0kB
Jan 23 14:12:25 HORST kernel: oom_reaper: reaped process 571 (kodi.bin), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB

So on the first look I was wondering running out of memory. So I monitored the memory every minute via:

ps aux >> /home/osmc/.kodi/temp/mem_usage.log
free >> /home/osmc/.kodi/temp/mem_usage.log

But the free memory when it crashed was 126988. Even the UI said about 400 MB free memory at this time.

My personal feeling is OutOfMemory is maybe missleading and the route cause is somewhere with too many open connections either to files or urls or databaseserver. So I monitored the server but there is most times only a couple of connections open from time to time and they are closed correctly.

Logs: Logs created on: 2018-01-23 14:40:34 - (Uptime = 5577.60)0wwkXuO5 : UNAME - Pastebin.com

Would be very very great if someone has some Idea and help to track the root cause.

Thx in
advance

2

Is there any reason why you’ve posted an abbreviated log? For example, I can’t see advancedsettings.xml or sources.xml.

The out-of-memory problem might be related to many things, including Kodi add-ons, but it’s clear that kodi.bin is hitting the memory pretty hard. The oom_score at the time kodi.bin was killed was 879, indicating that it had used 87.9% of the available memory.

I’d recommend that you disable all the add-ons you’ve installed yourself, as well as hyperion, and see if the problem persists.

3

I did disabled all addons, the only addon which was still running was the hyperion. See also my comments above. Even a fresh install had the same issues. The logs I attached are without any activated addon. Only hyperion was running and the UI titan active.

Currently investigating and comparing my rpi2 version and rpi3 version and i see that the rpi2 has only about 200 open files. But the rpi3 is opening more and more files and crash at around 1200 open files:

processId=$(ps -fu osmc | grep kodi.bin | grep -v grep | awk '{print $2}')
sudo lsof -p $processId | wc -l >> /home/osmc/.kodi/temp/mem_usage.log
free >> /home/osmc/.kodi/temp/mem_usage.log
 
number of open files when last crash 1300 and free memory 189884. Swap empty.
4

Advancedsettings is in the logs shown :wink:

Contents of special://profile/advancedsettings.xml are...
                                        <?xml version="1.0" encoding="utf-8" ?>
                                        <advancedsettings>
                                          <videodatabase>
                                            <name>MyVideos</name>
                                            <host>192.168.2.20</host>
                                            <user>xbmc</user>
                                            <pass>*****</pass>
                                            <type>mysql</type>
                                            <port>3306</port>
                                          </videodatabase>
                                          <musicdatabase>
                                            <name>MyMusic</name>
                                            <host>192.168.2.20</host>
                                            <user>xbmc</user>
                                            <pass>*****</pass>
                                            <type>mysql</type>
                                            <port>3306</port>
                                          </musicdatabase>
                                          <videolibrary>
                                            <importwatchedstate>true</importwatchedstate>
                                            <importresumepoint>true</importresumepoint>
                                          </videolibrary>
                                          <hosts>
                                            <entry name="NASSKU1">192.168.2.88</entry>
                                            <entry name="OSMC">192.168.2.103</entry>
                                          </hosts>
                                          <cache>
                                            <memorysize>157286400</memorysize>
                                            <buffermode>1</buffermode>
                                            <readfactor>4.0</readfactor>
                                          </cache>
                                          <pvr>
                                            <minvideocachelevel>30</minvideocachelevel>
                                            <minaudiocachelevel>30</minaudiocachelevel>
                                          </pvr>
                                          <loglevel hide="false">0</loglevel>
                                          <jsonrpc>
                                            <compactoutput>false</compactoutput>
                                            <tcpport>9090</tcpport>
                                          </jsonrpc>
                                        </advancedsettings>
5

While the underlying processors of the Pi2 and Pi3 are different, the OSMC install should be identical. If they are behaving differently, try moving the SD card from the Pi2 to the Pi3 (and, if you feel the urge, vice versa).

Then there was no reason to exclude it from the log, was there? You didn’t address why sources.xml isn’t there, of course.

6

I did not included sources.xml since I was guessing this is not related while so many file decriptors get consumed and I am not facing any issues with the sources.xml and the configured samba shares.

Why are you complaining about the advancedsettings.xml if we both can see it in the log ? Is it just that it is not exlicity added as a seperate section ?!

7

I will now run a new boot with the debugging enabled and no hyperion acivated any more.

But I can see already a main difference which I could not explain since the build is new and any addon is deactivated. On the rpi3 I am getting every second :

18:03:12.199 T:1540911872   DEBUG: JSONRPC Server: New connection detected
18:03:12.200 T:1540911872    INFO: JSONRPC Server: New connection added
18:03:12.205 T:1540911872    INFO: JSONRPC Server: Disconnection detected

This is never the case on the rpi2 with a very old build but based on the same release and also acivated JSONRPC.

I am wondering how can I debug JSONRPC since I have no Idea where these connection can come from.

8

Try running sudo netstat -tnp and see which IP addresses are connected to kodi.bin. Do you, for example, have a phone running Kore?

9

Thank you very much, I guess I have found the problem and the netstats seems to evidence this also.
The was a websocket tool in the network which was wrong configured and tried to connect to kodi on port 9090
Once I have killed this tool I git rid if the JSONRPC calls I have seen in the logs.

I have to prove it a little bit more, but right now seems that this tools keeps thounds of connections open which consumes over time the memory and all file handler of kodi.

I will provide an update here tomorrow if this was the root cause.

Many thx so far.

10

Thats was the issue. Solved now. Many thx