Sporadische segfaults bei sh.py 1.4.2 - Iskra Plugin ursächlich?

[Morg]

Moin,

ich habe hin und wieder segfaults vom smarthome.py Prozess, Version 1.4.2.master (0dff0244). Läuft auf einem RasPi 2B mit raspbian 9.3, Image über nfs vom Server (SD-Karte nur für Bootloader), stabile Stromversorgung, drei USB-IR-Leseköpfe.

Die letzten Zeilen im Logfile (mit -d) sind

2018-03-03  21:37:50 DEBUG    Scheduler    plugins.visu_websocket.series next time: 2018-03-03 21:38:00+01:00
 2018-03-03  21:37:51 DEBUG    Scheduler    RRDtool next time: 2018-03-03 21:38:21+01:00
 2018-03-03  21:37:56 DEBUG    Scheduler    sh.connections next time: 2018-03-03 21:38:06+01:00
 2018-03-03  21:38:00 DEBUG    Scheduler    plugins.visu_websocket.series next time: 2018-03-03 21:38:10+01:00
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:34545 to 0.0.0.0:42000
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:42644 to 0.0.0.0:42001
 2018-03-03  21:38:04 DEBUG    Main         Item d.heizung.tempvl = 43.4 via network 127.0.0.1 None
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:33041 to 0.0.0.0:42002
 2018-03-03  21:38:04 DEBUG    Main         Item d.heizung.temprl = 34.79 via network 127.0.0.1 None
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:55431 to 0.0.0.0:42003
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:42130 to 0.0.0.0:42004
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:53151 to 0.0.0.0:42005
 2018-03-03  21:38:04 DEBUG    Main         Item d.heizung.spdkomp = 0.0 via network 127.0.0.1 None
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:50691 to 0.0.0.0:42006
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:46353 to 0.0.0.0:42007
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:38166 to 0.0.0.0:42008
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:41721 to 0.0.0.0:42009
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:46868 to 0.0.0.0:42010
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:41713 to 0.0.0.0:42011
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:50104 to 0.0.0.0:42012
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:46419 to 0.0.0.0:42013
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:38754 to 0.0.0.0:42014
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:47063 to 0.0.0.0:42015
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:53718 to 0.0.0.0:42016
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:51991 to 0.0.0.0:42017
 2018-03-03  21:38:04 DEBUG    Main         UDPDispatcher: incoming connection from 127.0.0.1:59212 to 0.0.0.0:42018
 2018-03-03  21:38:04 DEBUG    Scheduler    iskra next time: 2018-03-03 21:38:34+01:00
 2018-03-03  21:38:06 DEBUG    Scheduler    sh.connections next time: 2018-03-03 21:38:16+01:00
 2018-03-03  21:38:07 DEBUG    iskra        cycle takes 3 seconds
 2018-03-03  21:38:10 DEBUG    iskra        Item d.haus.verbrauch = 860 via Logic None None
 2018-03-03  21:38:10 DEBUG    iskra        Item d.haus.zaehler = 12954.001 via Logic None None
 2018-03-03  21:38:10 DEBUG    iskra        cycle takes 3 seconds
 2018-03-03  21:38:11 DEBUG    Scheduler    plugins.visu_websocket.series next time: 2018-03-03 21:38:21+01:00
 2018-03-03  21:38:16 DEBUG    Scheduler    sh.connections next time: 2018-03-03 21:38:26+01:00

Im Syslog ist nichts zu finden. Aktive Plugins sind backend, knx, avm, websocket, cli, iskra (*), rrd, nw, yamahayxc (*), notify. iskra und yamahayxc sind fremd bzw. selbst geschrieben.

Ein Problem für mich ist, dass die segfaults so selten sind (teilweise läuft das Ding 2 Wochen, mal nur Stunden), dass ich sie nicht planmäßig reproduzieren kann.

Hat jemand von euch eine Idee, wo ich ggf. gezielter suchen kann oder (prophylaktisch) ggf. relevante Daten sammeln kann?

[psilo]

mindestens könntest du mal die plugins testweise deaktivieren, auch wenn das "weh tut"... dann kannst du diese zumindest ausschliessen.. ggf mal ein anderes python probieren? welche version ist denn drauf?

[Morg]

Plugins kann ich mal rausnehmen - alle? zumindest knx müsste drinbleiben, sonst wärs irgendwie blöd

python 3.5.3

Habe jetzt backend, iskra, yamahayxc rausgeworfen, weil die wahrscheinlich eher selten sind. Mal sehen, was jetzt passiert...

[Msinn]

Ich würde erstmal die Beiden mit * rausnehmen.

Die anderen Plugins die ich nicht kenne und von denen ich nicht weiss wie verbreitet sie sind wären: rrd, nw, notify. Die würde ich rausnehmen, wenn das Problem weiter besteht.

[Morg]

Ich gehe derzeit mal davon aus, dass es das iskra-Plugin war - ich glaube, dass ist noch "Alt-Code" und nicht auf smartplugin-Stand. Das werde ich mir wohl mal etwas genauer ansehen müssen. Mit (wieder) aktiviertem Yamaha-Plugin läuft es jetzt seit 3 Tagen ohne segfault...

[psilo]

wo ist das her? nicht smartplugin ist nicht das problem. eher dass es vermutlich alpha ist, wie viele andere plugins auch

[Morg]

Das ist mal hier aus dem Forum genommen. Ist ein angepasstes Plugin für eHZ von Fa. Iskra - die schicken leider keine lesbaren Strings, sondern reines Binärformat, daher ist da noch etwas Parsing mit dabei.
Das hat bisher (also bewusst vor 1.4.2) problemlos funktioniert (seit... 1-2 Jahren)

[psilo]

das import serial referenziert auf das hier, oder?
http://pythonhosted.org/pyserial/index.html

Die Frage ist, ob Du beim Upgrade ggf. das Paket mit pip in neuerer Version installiert hast, die jetzt ggf. die Probleme macht.
Oder hast Du die Hardware gewechselt?

der rest sieht m.E. unkritisch aus.. kann mir nur gut vorstellen, dass beim lesen des seriellen interfaces was scheppert..

[Morg]

Nee, gleiche Hardware, gleiche Py-Version usw.

Ich habe jetzt das Ding mal etwas entschlackt und mit pep8 die Syntax "verschönert", bislang läuft es problemlos. Allerdings sehe ich auch, dass es die beiden Zähler (habe zwei) nicht gleichmäßig abfragt. Der eine setzt immer schonmal zwei bis fünf Zyklen aus und ist dann wieder da; Fehlermeldungen bekomme ich allerdings keine...

[psilo]

auch gleiche paketversion bei pyserial?

[bmx]

Also ich würde mal vermuten, das es in den Umwandlungsfunktionen vom ISKRA Plugin kracht. Also dort wo aus einem Teil der Daten data[i+1:i+2] ein integer extrahiert wird. Da scheint keine Überprüfung stattzufinden, ob der Index tatsächlich ok ist. Das wäre ein Ansatzpunkt.

[henfri]

Aber kann das zum Segfault führen?

[bmx]

Du könntest mal versuchen mehr Informationen zu gewinnen durch die Nutzung des faulthandler beim Start von Python.
Um Python zu crashen gibt es hier mehr Informationen.

[Morg]

Bei mir gab es aus privaten Gründen etwas Pause (nur nutzen, nicht dran arbeiten)...

Ich habe mich jetzt mal hingesetzt, die Logik des Plugins verstanden und das Debug-Logging sowie einige Fehlerabfragen ergänzt. Bislang keine segfaults, aber es läuft gerade noch im Testmodus.

Wenn ich mich daran machen möchte, das Plugin auf SmartPlugin umzustellen - gibt es eine Doku, die das einigermaßen erklärt? Auf der sh.py-Homepage ist zwar etwas Doku, aber die hat mir bisher nicht wirklich geholfen...

[bmx]

Hast Du Mal das SMLX Plugin zu nutzen? Auf den ersten Blick sieht es für mich so aus, als ob der Zähler SML spricht. In dem Fall kannst Du Dir die Portierung sparen.
Anderenfalls kannst du Dir das Template eines Smartplugin nehmen und die alten Sachen einfach dort reinkopieren.