Homegear 0.8.x instabil / Received Signal 6


#1

Hallo,

es ist einfach zum Haare raufen. Wie Ihr in einem anderen Post von mir lesen könnt, betreibe ich seit längerem eine Installation mit 3 HomeGear-Gateways, jeweils auf einem Raspberry Pi 3 mit CC1101. Die 3 Gateway-PIs sind irre stabil, ich musste seit Ewigkeiten keinen mehr davon rebooten. (Build 2362).

Die Homegear-Installation die Ärger macht ist jene, die sich auf einem Intel-NUC-System befindet und dort in einem Docker Container ihr dasein fristet. Konkret ist es eine AMD64 Installation des ResinOS basierenden HomeAssistant (HA). Wobei der HA in zwischen eher selten so installiert wird. Aber um auf einem NUC zu laufen geht es “nicht anders”.

Ich habe dafür also ein eigenes Repo angelegt, mit dem eine Docker-Installation spezifisch für ResinOS und HA ausgerollt wird. Bis auf die Prozesspriorisierung wird dort alles “nach Handbuch” umgesetzt. Er startet einwandfrei, holt sich seine Datenbank vom lokalen Share (kein Fileshare, sondern gesharedtes Verzeichnis im Docker-Context), etc. Nach einer Weile erfolgt die Meldung SigAbrt caught Signal 6, und der Daemon wird von der übergeordneten Homegear-Instanz neugestartet.

Zunächst “behob” ich das Problem, in dem ich HA so scriptete das er 2 Minuten nach dem letzten Empfang einen Reconnect zum HomeGear machte. Ja ich hatte keine Zeit und keinen Nerv dem Problem näher auf den Grund zu gehen. Es gab halt irdische Dinge, die einfach wichtiger waren. (Docker-Build mit 2362)

Am zurückliegenden Wochenende fand ich endlich Zeit zu genaueren Fehleranalyse (und einem Update auf die 2374). Ich drehte also in der main.cfg den Debugging-Wert auf 5 und starte die Docker-Instanz neu.

Der Fehler der vorher sporadisch alle 5-120 Minuten auftrat, kam bis jetzt 36 Stunden nicht mehr vor. Soll es das gewesen sein? Nein, denn bei jeder dieser Fehlermeldungen, kam ja auch die Info, das ein Core-Dump geschrieben worden sein soll. In dem Verzeichnis findet sich aber keiner.
Dafür laufen nun die Logs “voll”.

Ich überlege nun das Debugging wieder zu begrenzen, aber wenn keine Core-Dumps produziert werden, obwohl es so eingestellt ist, wo soll ich dann noch suchen?
Vielleicht hat ja jemand von Euch eine Idee.


#2

Nach anderthalb Tagen jetzt mal wieder ein Schluck auf. Folgendes habe ich dazu im Log gefunden:

11/21/18 01:22:49.550 Module HomeMatic BidCoS: HomeMatic Homegear Gateway "HM-RPi-CC1101-LIVING": Debug: TCP packet received: 42696E00000000480000000E7061636B6574526563656976656400000002000000D10000000000000000000000030000001E304445413834313032463241433646443033373630363031323230303138
11/21/18 01:22:49.550 Module HomeMatic BidCoS: HomeMatic Homegear Gateway "HM-RPi-CC1101-OFFICE": Debug: TCP packet received: 42696E00000000480000000E7061636B6574526563656976656400000002000000D10000000000000000000000030000001E304445413834313032463241433646443033373630363031323230304339
11/21/18 01:22:49.551 Debug (HM-RPi-CC1101-LIVING): Packet 0DEA84102F2AC6FD037606012200 enters raisePacketReceived.
11/21/18 01:22:49.551 Debug (HM-RPi-CC1101-LIVING): Packet 0DEA84102F2AC6FD037606012200 is now passed to the EventHandler.
11/21/18 01:22:49.550 HomeMatic BidCoS packet received (HM-RPi-CC1101-LIVING, RSSI: -62 dBm): 0DEA84102F2AC6FD037606012200
11/21/18 01:22:49.551 Devlog (HM-RPi-CC1101-LIVING): Getting peer for packet 0DEA84102F2AC6FD037606012200.
11/21/18 01:22:49.551 Debug (HM-RPi-CC1101-OFFICE): Packet 0DEA84102F2AC6FD037606012200 enters raisePacketReceived.
11/21/18 01:22:49.552 Devlog (HM-RPi-CC1101-LIVING): Packet 0DEA84102F2AC6FD037606012200 is now passed to checkForBestInterface.
11/21/18 01:22:49.552 Debug (HM-RPi-CC1101-OFFICE): Packet 0DEA84102F2AC6FD037606012200 is now passed to the EventHandler.
11/21/18 01:22:49.551 HomeMatic BidCoS packet received (HM-RPi-CC1101-OFFICE, RSSI: -101 dBm): 0DEA84102F2AC6FD037606012200
11/21/18 01:22:49.552 Devlog (HM-RPi-CC1101-OFFICE): Getting peer for packet 0DEA84102F2AC6FD037606012200.
11/21/18 01:22:49.552 Devlog (HM-RPi-CC1101-OFFICE): Packet 0DEA84102F2AC6FD037606012200 is now passed to checkForBestInterface.
11/21/18 01:22:49.553 Devlog (HM-RPi-CC1101-LIVING): checkForBestInterface finished.
11/21/18 01:22:49.553 Devlog (HM-RPi-CC1101-LIVING): Packet 0DEA84102F2AC6FD037606012200 is now passed to _receivedPackets.set.
11/21/18 01:22:49.553 Devlog (HM-RPi-CC1101-LIVING): _receivedPackets.set finished.
11/21/18 01:22:49.553 Devlog (HM-RPi-CC1101-LIVING): Packet 0DEA84102F2AC6FD037606012200 is now passed to the peer.
11/21/18 01:22:49.553 Module HomeMatic BidCoS: Info: BRIGHTNESS on channel 1 of HomeMatic BidCoS peer 35 with serial number LEQ0797360 was set to 0x22.
11/21/18 01:22:49.553 Module HomeMatic BidCoS: Info: ERROR on channel 1 of HomeMatic BidCoS peer 35 with serial number LEQ0797360 was set to 0x00.
11/21/18 01:22:49.553 Debug (HM-RPi-CC1101-LIVING): Packet processing of packet 0DEA84102F2AC6FD037606012200 took 2 ms.
11/21/18 01:22:49.553 RPC client: Debug: Calling RPC method "system.multicall" on server 172.16.112.101.
11/21/18 01:22:49.553 RPC client: Parameters:
(Array length=1)
{
  (Struct length=2)
  {
    [methodName]
    {
      (String) event
    }
    [params]
    {
      (Array length=4)
      {
        (String) homeassistant-hmwireless
        (String) LEQ0797360:0
        (String) RSSI_DEVICE
        (Integer) -62
      }
    }
  }
}
11/21/18 01:22:49.553 Debug: Calling getFileDescriptor...
11/21/18 01:22:49.554 Debug: Connecting to host 172.16.112.101 on port 34409...
11/21/18 01:22:49.554 Debug: Connected to host 172.16.112.101 on port 34409. Client number is: 108825
11/21/18 01:22:49.554 RPC client: Debug: Sending packet: POST /RPC2 HTTP/1.1
User-Agent: Homegear 0.8.0-2374
Host: 172.16.112.101:34409
Content-Type: text/xml
Content-Length: 456
Connection: close

<?xml version="1.0"?>
<methodCall><methodName>system.multicall</methodName><params><param><value><array><data><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>homeassistant-hmwireless</value><value>LEQ0797360:0</value><value>RSSI_DEVICE</value><value><i4>-62</i4></value></data></array></value></member></struct></value></data></array></value></param></params></methodCall>
11/21/18 01:22:49.557 Signal 6 received.
11/21/18 01:22:49.574 Info: Process with id 31803 ended.
11/21/18 01:22:49.574 Error: Core was dumped.

#3

Hallo @Krys1976,

Voraussetzung, dass ein Coredump geschrieben wird, ist, dass der ausführende Benutzer dies darf (ulimit -c für den Benutzer muss unlimited (oder zumindest groß genug) sein). Sonst gibt es keines. Tatsächlich würde eine Analyse des Coredumps helfen. Aber nur, wenn es tatsächlich ein Problem in Homegear selbst ist. Analysieren kannst du das Ganze am besten im Dockercontainer selbst, über den hier beschriebenen Weg: Error: More than 1000 packets are queued to be processed

Ich hoffe das hilft schon einmal… Im Zweifel installier Homegear auf einem dedizierten Raspberry Pi. Da läuft das Ganze auf jeden Fall stabil.

Viele Grüße

Sathya


#4

Hallo Sathya,

ich habe es leider weder geschafft irgendwie weitere Core-Dumps von der Platte zu bekommen noch eine genauere Analyse. Allerdings habe ich inzwischen eine schwer erreichbare HM-Komponente durch eine neue ausgetauscht. Letztendlich mit Erfolg, denn diese Signal 6 Geschichten sind passé.

Ich werde irgendwann mit Zeit, die teildefekte HM-Komponente nochmal in Betrieb nehmen. Schließlich sollte HomeGear sich nicht dran stören, wenn da ein Teil nicht so tut wie es soll.

Schönen Gruß

Krys