RPC Connection limit

Deutsche Foren Fehler
#1

Hallo zusammen,

ich habe in letzter Zeit vermehrt Probleme mit folgenden Fehlern im Logfile. Homegear ist dann praktisch auch nicht mehr nutzbar. Der Fehler führt auch dazu, dass dann beispielsweise auch die SPI-Konfiguration versagt.

10/06/16 12:56:36.565 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:37.567 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:38.569 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:39.570 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:40.572 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:41.574 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:42.575 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:43.577 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:44.578 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/06/16 12:56:45.580 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.

Die Verbindungen sehen wie folgt aus:
root@alarmsystem:~# netstat -anp | grep 2001
tcp 0 0 0.0.0.0:2001 0.0.0.0:* LISTEN 9605/homegear
tcp 1 0 192.168.0.199:2001 192.168.0.199:49817 CLOSE_WAIT 9605/homegear
tcp 1 0 192.168.0.199:2001 192.168.0.199:49828 CLOSE_WAIT 9605/homegear
tcp 1 0 192.168.0.199:2001 192.168.0.199:49800 CLOSE_WAIT 9605/homegear
tcp 1 0 192.168.0.199:2001 192.168.0.199:49805 CLOSE_WAIT 9605/homegear
…

Hat das schon einmal jemand gesehen? Ich verbinde mich per RPC von Java aus, aber dort kann ich kein Problem erkennen. Dort nutze ich auch vielfach eingesetzte Komponenten von Apache.

Ich würde sagen, es hat etwas mit den “Pushes” zu tun, also den RCP-Calls von Homegear zu meiner Applikation!?!

root@alarmsystem:~# lsof -i TCP

COMMAND     PID      USER   FD   TYPE  DEVICE SIZE/OFF NODE NAME
homegear   9605  homegear   15u  IPv4 1129289      0t0  TCP alarmsystem.lan:2001->alarmsystem.lan:49791 (CLOSE_WAIT)
homegear   9605  homegear   16u  IPv4 1129968      0t0  TCP alarmsystem.lan:2001->alarmsystem.lan:49792 (CLOSE_WAIT)
homegear   9605  homegear   17u  IPv4 1129969      0t0  TCP alarmsystem.lan:2001->alarmsystem.lan:49793 (CLOSE_WAIT)
homegear   9605  homegear   18u  IPv4 1129970      0t0  TCP alarmsystem.lan:2001->alarmsystem.lan:49794 (CLOSE_WAIT)
#2

Hallo @vctender1,

da hängt irgendwas. Kannst du mir ein Logfile schicken, welches Normalfunktion und Übergang zum Fehler zeigt? Poste mir außerdem deine Homegear-Version.

Viele Grüße

Sathya

#3

Also die Probleme treten offenbar in Etappen auf.

Zunächst stoppt die SPI-Kommunikation. Dass der Philips Hue nicht erreicht wird, hat nichts mit dem Thema zu tun. Der verliert irgendwie aktuell mit der Zeit seine IP und bekommt keine neue.

10/05/16 07:33:22.175 HomeMatic BidCoS packet received (CC1101, RSSI: -54 dBm): 0C9684702D327900000000D72E
10/05/16 07:33:22.176 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.0.199.
10/05/16 07:33:22.176 Module HomeMatic BidCoS: Info: HUMIDITY on channel 1 of HomeMatic BidCoS peer 13 with serial number LEQ0598003 was set to 0x2E.
10/05/16 07:33:22.176 Module HomeMatic BidCoS: Info: TEMPERATURE on channel 1 of HomeMatic BidCoS peer 13 with serial number LEQ0598003 was set to 0x00D7.
10/05/16 07:33:22.209 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.0.199.
10/05/16 07:33:29.728 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:33:31.395 HomeMatic BidCoS packet received (CC1101, RSSI: -65 dBm): 0CDD847035AC1200000000D82F
10/05/16 07:33:31.396 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.0.199.
10/05/16 07:33:31.397 Module HomeMatic BidCoS: Info: HUMIDITY on channel 1 of HomeMatic BidCoS peer 34 with serial number LEQ1480984 was set to 0x2F.
10/05/16 07:33:31.397 Module HomeMatic BidCoS: Info: TEMPERATURE on channel 1 of HomeMatic BidCoS peer 34 with serial number LEQ1480984 was set to 0x00D8.
10/05/16 07:33:31.453 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.0.199.
10/05/16 07:33:44.781 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:33:59.828 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:34:14.877 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:34:29.931 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:34:44.990 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:35:00.041 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:35:15.090 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:35:30.138 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:35:45.193 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:36:00.243 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:36:15.291 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:36:30.348 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 07:36:45.402 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success

Ab dem Zeitpunkt wird keinerlei SPI-Konfiguration mehr geloggt.

Meine Haussteuerung versucht dann immer wieder Nachrichten einzustellen (welche SPI benötigen). Diese gehen aber offenbar nicht raus … vermutlich blockieren dann auch die RPC-Threads:

10/05/16 09:52:57.767 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 09:53:12.816 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 09:53:27.875 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 09:53:42.928 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 09:53:57.976 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 09:54:11.082 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49832 accepted. Client number: 15208
10/05/16 09:54:11.083 RPC Server (Port 2001): Info: RPC server client id for client number 15208 is: 2175
10/05/16 09:54:11.087 RPC Server (Port 2001): Info: Client number 15208 is calling RPC method: setValue (1) Parameters:
(Integer) 35
(Integer) 2
(String) STATE
(Boolean) 0
10/05/16 09:54:11.112 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49833 accepted. Client number: 15209
10/05/16 09:54:11.112 RPC Server (Port 2001): Info: RPC server client id for client number 15209 is: 2176
10/05/16 09:54:11.116 RPC Server (Port 2001): Info: Client number 15209 is calling RPC method: setValue (1) Parameters:
(Integer) 25
(Integer) 2
(String) STATE
(Boolean) 1
10/05/16 09:54:11.171 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49834 accepted. Client number: 15210
10/05/16 09:54:11.172 RPC Server (Port 2001): Info: RPC server client id for client number 15210 is: 2177
10/05/16 09:54:11.176 RPC Server (Port 2001): Info: Client number 15210 is calling RPC method: setValue (1) Parameters:
(Integer) 24
(Integer) 2
(String) STATE
(Boolean) 1
10/05/16 09:54:11.216 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49835 accepted. Client number: 15211
10/05/16 09:54:11.217 RPC Server (Port 2001): Info: RPC server client id for client number 15211 is: 2178
10/05/16 09:54:11.220 RPC Server (Port 2001): Info: Client number 15211 is calling RPC method: setValue (1) Parameters:
(Integer) 12
(Integer) 2
(String) STATE
(Boolean) 1
10/05/16 09:54:11.270 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49836 accepted. Client number: 15212
10/05/16 09:54:11.271 RPC Server (Port 2001): Info: RPC server client id for client number 15212 is: 2179
10/05/16 09:54:11.274 RPC Server (Port 2001): Info: Client number 15212 is calling RPC method: setValue (1) Parameters:
(Integer) 12
(Integer) 1
(String) STATE
(Boolean) 0
10/05/16 09:54:11.330 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49837 accepted. Client number: 15213
10/05/16 09:54:11.331 RPC Server (Port 2001): Info: RPC server client id for client number 15213 is: 2180
10/05/16 09:54:11.334 RPC Server (Port 2001): Info: Client number 15213 is calling RPC method: setValue (1) Parameters:
(Integer) 25
(Integer) 1
(String) STATE
(Boolean) 1
10/05/16 09:54:11.382 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49838 accepted. Client number: 15214
10/05/16 09:54:11.382 RPC Server (Port 2001): Info: RPC server client id for client number 15214 is: 2181
10/05/16 09:54:11.385 RPC Server (Port 2001): Info: Client number 15214 is calling RPC method: setValue (1) Parameters:
(Integer) 24
(Integer) 1
(String) STATE
(Boolean) 1
10/05/16 09:54:11.459 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49839 accepted. Client number: 15215
10/05/16 09:54:11.460 RPC Server (Port 2001): Info: RPC server client id for client number 15215 is: 2182
10/05/16 09:54:11.463 RPC Server (Port 2001): Info: Client number 15215 is calling RPC method: setValue (1) Parameters:
(Integer) 35
(Integer) 1
(String) STATE
(Boolean) 0
10/05/16 09:54:13.023 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 09:54:28.073 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 09:54:43.120 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success

Der Stau wird irgendwann zu groß:

10/05/16 10:16:47.456 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 10:17:02.510 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 10:17:17.559 Module Philips hue: Philips hue bridge "phue": Error: Command was not send to Hue Bridge: Could not get address information: Success
10/05/16 10:17:23.076 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49840 accepted. Client number: 15216
10/05/16 10:17:23.076 RPC Server (Port 2001): Info: RPC server client id for client number 15216 is: 2183
10/05/16 10:17:23.080 RPC Server (Port 2001): Info: Client number 15216 is calling RPC method: setValue (1) Parameters:
(Integer) 35
(Integer) 1
(String) STATE
(Boolean) 0
10/05/16 10:17:23.105 RPC Server (Port 2001): Info: Connection from 192.168.0.199:49841 accepted. Client number: 15217
10/05/16 10:17:23.106 RPC Server (Port 2001): Info: RPC server client id for client number 15217 is: 2184
10/05/16 10:17:23.106 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/05/16 10:17:23.110 RPC Server (Port 2001): Info: Client number 15217 is calling RPC method: setValue (1) Parameters:
(Integer) 25
(Integer) 1
(String) STATE
(Boolean) 1
10/05/16 10:17:23.164 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/05/16 10:17:23.172 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/05/16 10:17:23.221 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.
10/05/16 10:17:23.228 RPC Server (Port 2001): Error: There are too many clients connected to me. Closing incoming connection. You can increase the number of allowed connections in main.conf.

Ich bin mit einem Nightly unterwegs:
root@alarmsystem:/var/log/homegear# homegear -v
Homegear version 0.7.0-1393

#4

Kannst du mir das ganze Log per E-Mail an sathya@homegear.email senden?

#5

mache ich heute Abend. Kann ich erst tun, wenn ich zu Hause bin.

#6

Hallo @vctender1,

ich schaue mir gerade dein Log an, sehe auf Anhieb aber noch nicht, warum er hängt (ich schaue gleich noch weiter). Könntest du einmal Folgendes machen:

  • gdb und libc-Debuginformationen mit “apt-get install gdb libc6-dbg” installieren.
  • Dann sobald er hängt die Prozess-ID des Homegearprozesses mit “ps -ejH -1 | grep homegear” ermitteln.

Die Ausgabe sollte etwa so aussehen:

 9071  9070  9017 pts/0    S+     0:00               grep homegear
18132 18132 18132 ?        SLsl 1440:51   /usr/bin/homegear -u homegear -g homegear -p /var/run/homegear/homegear.pid
18559 18559 18559 ?        SLsl 270:44     homegear -c /etc/homegear/ -rse

Der korrekte Prozess ist “/usr/bin/homegear -u homegear -g homegear -p /var/run/homegear” in diesem Fall ist die ID also 18132. Im Anschluss startest du gdb mit

gdb homegear 18132

Schick mir die Ausgabe von:

thread apply all bt

Dann sehe ich, wo er hängt und wir sollten das Problem lösen können.

Viele Grüße

Sathya

#7

6 posts were split to a new topic: Homegear-RPC und Java