Homematic wired

exot · 01 September 2015, 08:50:37

Hallo Ralf,
Dumme

Frage zwischendurch.
Autor: BrainHunter

ZitatWenn Du den HM485d manuell startest müsste beim Starten folgendes im log des HM485d stehen:

HM485d: port 2000 opened
HM485d: server waiting for client connection on port 2000
Opening SERIAL device /dev/ttyUSB0
SERIAL device opened
HM485d: SERIALbaudrate=19200, databits=8, parity=even, stopbits=1, handshake=none
HM485d: SERIAL connected to device /dev/ttyUSB0
HM485d: Server started ...

Habe ich richtig gelesen, dass soll im Logfile des hM485d stehen.
Bei mir gibt es unter HM485 keinen Log file.
Oder bringe ich da was durcheinander.
Gruß Michael

Ralf9 · 01 September 2015, 10:09:24

Zitat von: exot am 01 September 2015, 08:50:37
Habe ich richtig gelesen, dass soll im Logfile des hM485d stehen.
Bei mir gibt es unter HM485 keinen Log file.
Oder bringe ich da was durcheinander.

Das HM485d log gibt es normalerweise nicht. Es ist bei der Fehlersuche- und eingrenzung auf dem Bus recht hilfreich.
Es sollte normalerweise nicht aktiv sein um unnötige Rechnerlast zu vermeiden.
Es kann in fhem aktiviert werden indem in der HM485d_CommandLine über die Attribute folgendes ergänzt wird:

Code Auswählen

--logfile ./log/HM485.log --verbose 4

Eine log Ausgabe bekommt man auch wenn man den HM485d manuell auf der Konsole startet (siehe Internal HM485d_CommandLine).
In der fhem.cfg muß dann "bind 0" stehen.

Gruß Ralf

exot · 01 September 2015, 11:37:16

Hallo Ralf,
Danke für Deine Info.
Damit ist meine Frage beantwortet.
Gruß Michael

BrainHunter · 01 September 2015, 21:30:05

Ich habe mir mal die Mühe gemacht das Ganze nachzustellen: Dazu habe ich auf meinem Desktoprechner, den ich als Fhem Testsystem verwende, das Problem nachgestellt.
--> Fhem update gemacht und HM485 war auch schon drauf.

Zuerst habe ich Tests gemacht mit FHEM komplett. Da habe ich dann bemerkt das es manchmal zu funktionieren scheint und manchmal nicht!
Um nicht immer neu zu starten habe ich nach jedem Versuch die Schnittstelle auf 9600 zurückgestellt:

Code Auswählen


# sudo stty -F /dev/ttyUSB0 9600

Also weiter mit Versuchen nur mit dem HM485d.pl:
In einem Terminal lasse ich mir mit "tail -f" die HM485.log anzeigen:

Code Auswählen

tail -f /opt/fhem/log/HM485.log
im nächsten Terminal zeige ich den Status der Schnittstelle an:

Code Auswählen

sudo watch -n1 stty -F /dev/ttyUSB0
Im dritten Terminal starte ich den HM485d.pl:

Code Auswählen

./FHEM/lib/HM485/HM485d/HM485d.pl --serialNumber SGW0123456 --device /dev/serial/by-id/usb-FI_FT232R_USB_UART_A6036LQ5-if00-port0 --localPort 2000 --logfile ./log/HM485.log --verbose 5

und wieder: mal gehts, mal nicht...
Warum?
->Mal sehen was das der Service so macht mit der Schnittstelle:

Code Auswählen

strace -fftto strace.out -e trace=open,ioctl,close,clone -E username=fhem ./FHEM/lib/HM485/HM485d/HM485d.pl --serialNumber SGW0123456 --device /dev/serial/by-id/usb-FI_FT232R_USB_UART_A6036LQ5-if00-port0 --localPort 2000 --logfile ./log/HM485.log --verbose 5

Den erzeugten Logfiles nach würde ich sagen, es handelt sich um ein Timing Problem beim Starten des Services.
Hier mal 2 Ausschnitte (Zum Verständnis: FD5 ist die Serielle Schnittstelle):

Code (Funktionsfähig) Auswählen


20:49:46.866768 open("./log/HM485.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 4
20:49:46.866857 ioctl(4, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7ffc13561ff0) = -1 ENOTTY (Inappropriate ioctl for device)
20:49:46.867188 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f65e8c159d0) = 10548
20:49:46.870694 close(5)                = 0
20:49:46.870816 ioctl(5, TCFLSH, 0x2)   = -1 EBADF (Bad file descriptor)
20:49:46.870951 ioctl(5, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7ffc13561eb0) = -1 EBADF (Bad file descriptor)
20:49:46.871002 ioctl(5, SNDCTL_TMR_START or SNDRV_TIMER_IOCTL_TREAD or TCSETS, {B9600 -opost -isig -icanon -echo ...}) = -1 EBADF (Bad file descriptor)
20:49:46.871079 close(5)                = -1 EBADF (Bad file descriptor)
20:49:46.871380 close(3)                = 0
20:49:46.874076 close(4)                = 0
20:49:46.875943 +++ exited with 0 +++

Code (FAIL) Auswählen


20:54:06.177936 open("./log/HM485.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 4
20:54:06.178026 ioctl(4, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7ffdd6bf93b0) = -1 ENOTTY (Inappropriate ioctl for device)
20:54:06.178330 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fe91d54c9d0) = 11287
20:54:06.182203 ioctl(5, TCFLSH, 0x2)   = 0
20:54:06.182359 ioctl(5, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, {B19200 -opost -isig -icanon -echo ...}) = 0
20:54:06.182413 ioctl(5, SNDCTL_TMR_START or SNDRV_TIMER_IOCTL_TREAD or TCSETS, {B9600 -opost -isig -icanon -echo ...}) = 0
20:54:06.186813 ioctl(5, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, {B9600 -opost -isig -icanon -echo ...}) = 0
20:54:06.186907 close(5)                = 0
20:54:06.187037 close(5)                = -1 EBADF (Bad file descriptor)
20:54:06.187393 close(3)                = 0
20:54:06.189912 close(4)                = 0
20:54:06.191854 +++ exited with 0 +++

Wie man sieht ist der close(5) Call nicht immer an der selben Position und dann wird die Schnittstelle auf 9600 zurückgesetzt! -> Logisch

Die kompletten Logfiles habe ich mal angehängt. Kann sich das mal bitte jemand ansehen?
Was generel auffällt ist, dass sehr oft ioctl() aufgerufen wird. Ich habe in den Code nicht reingesehen, aber ich vermute mal, dass ist so nicht gewollt.

Ralf9 · 01 September 2015, 22:28:34

Zitat von: BrainHunter am 01 September 2015, 21:30:05
Im dritten Terminal starte ich den HM485d.pl:
Code Auswählen Erweitern
./FHEM/lib/HM485/HM485d/HM485d.pl --serialNumber SGW0123456 --device /dev/serial/by-id/usb-FI_FT232R_USB_UART_A6036LQ5-if00-port0 --localPort 2000 --logfile ./log/HM485.log --verbose 5
und wieder: mal gehts, mal nicht...

Hast Du es auch mal mit /dev/ttyUSB0 als device versucht?

Code Auswählen

./FHEM/lib/HM485/HM485d/HM485d.pl --serialNumber SGW0123456 --device /dev/ttyUSB0 --verbose 4

Gruß Ralf

BrainHunter · 01 September 2015, 22:43:03

Zitat von: Ralf9 am 01 September 2015, 22:28:34
Hast Du es auch mal mit /dev/ttyUSB0 als device versucht?

Ja habe ich, nur vergessen zu erwähnen, aber das ändert nichts.
Macht auch Sinn, da /dev/serial/by-id/usb-FI_FT232R_USB_UART_A6036LQ5-if00-port0 nur ein Symlink auf /dev/ttyUSB0 ist.

Die Logfiles zeigen ja auch, dass das Problem nach dem clone() auftritt, wenn der startende Prozess seine noch offenen Filedecriptor schließt.

Ralf9 · 01 September 2015, 23:09:28

wenn es damit nicht funktioniert

Code Auswählen

./FHEM/lib/HM485/HM485d/HM485d.pl --serialNumber SGW0123456 --device /dev/ttyUSB0 --verbose 4
dann weiß ich auch nicht weiter. Du bist bist jetzt der einzigste der dieses Problem hat.

Verwendest Du die aktuelle Version von Thorsten? dev oder master?
Steht nach den Starten in fhem der HM485_LAN auf open.

Gruß Ralf

BrainHunter · 02 September 2015, 12:32:53

Ja ich verwende die dev von thorsten. Die genaue Version muss ich nachsehen.
Aber noch nicht alt.

BrainHunter · 02 September 2015, 17:58:58

Ich glaub ich habs:
Ich habe mir den Code mal angesehen und da ist mir aufgefallen, dass wenn ein Logfile angegeben ist wird geforked. Und genau hier ist das Problem!
Normalerweise muss man ja das Logfile nicht mit angeben: Dann funktioniert auch alles wunderbar, weil der Prozess die Schnittstelle auf macht und einfach verwendet. --> Alles super, FHEM loggt die Ausgaben vom HM485d über dessen stdout.

Ich habe aus mir nicht mehr bekannten Gründen HM485d_logfile definiert. Das führt dazu das nach dem Start des HM485d die Schnittstelle geöffnet wird und danach ein fork ausgeführt wird um den Prozess in den Hintergrund zu bringen.
Der ursprünglich gestartete Prozess wird beendet und stellt meistens die Schnittstelle wieder zurück auf die ursprüngliche Einstellung!
Ich konnte das Verhalten mehrfach nachvolziehen wenn ich die HM485d.pl manuell mit dem Schalter "--logfile ./log/HM485.log" gestartet habe.
Ein einfacher Fix wäre das Fork in der ServerTools.pm einfach an den Anfang zu stellen.

Das Ganze ist vermutlich einfach noch nicht aufgefallen bisher. Das Problem tritt vermutlich dann auf, wenn man den Service extra Startet und er sich in den Hintergrund schieben soll.

Ich hoffe mal das war eine kleine Hilfe. Wenn auch wohl sonst niemand bisher dieses Problem hatte.

grüße Nico

Ralf9 · 02 September 2015, 18:29:02

Zitat von: BrainHunter am 02 September 2015, 17:58:58
Der ursprünglich gestartete Prozess wird beendet und stellt meistens die Schnittstelle wieder zurück auf die ursprüngliche Einstellung!
Ich konnte das Verhalten mehrfach nachvolziehen wenn ich die HM485d.pl manuell mit dem Schalter "--logfile ./log/HM485.log" gestartet habe.

Du bist wahrscheinlich der erste der bei der seriellen Schnittstelle beim manuellen Start vom HM485d.pl den Schalter "--logfile ./log/HM485.log" mit angegeben hat.
Ich habe bis jetzt den HM485d.pl immer ohne "--logfile ./log/HM485.log" gestartet.

Mit dem fork kenne ich mich nicht aus.
In der "00_HM485_LAN.pm" wird bei bind 1 in der "sub HM485_LAN_HM485dStart($)" der HM485d.pl mit "system($HM485dCommandLine . '&');" im Hintergrund gestartet. Wird dann trotzdem in der ServerTools.pm bei einem --logfile das fork benötigt?

Gruß Ralf

Scotty80 · 02 September 2015, 22:09:02

Hallo,

bitte mal zum Verständnis: ist in der dev-Version 0.6.2 die Funktionalität des HMW-Sen-SC-12-Moduls schon voll implementiert?
Bzw. ab welcher für den Alltagsgebrauch geeigneten Version funktioniert dieses Modul?
Was ist der aktuelle STATE der Kanäle des Moduls? On und off? Open/Closed?

Gruß Scotty

BrainHunter · 02 September 2015, 22:30:11

Zitat von: Ralf9 am 02 September 2015, 18:29:02
Mit dem fork kenne ich mich nicht aus.
In der "00_HM485_LAN.pm" wird bei bind 1 in der "sub HM485_LAN_HM485dStart($)" der HM485d.pl mit "system($HM485dCommandLine . '&');" im Hintergrund gestartet. Wird dann trotzdem in der ServerTools.pm bei einem --logfile das fork benötigt?

Das ist so irgendwie nicht ganz optimal.
Das der HM485d.pl einen Fork machen kann ist sicherlich sinnvoll, z.b. wenn man ihn ohne bind laufen lassen möchte. Das das ganze an --logfile gekoppelt ist, finde ich nicht sehr glücklich gelöst. Ich denke ein extra Schalter wäre hierfür passender. Dann funktioniert Beides auch getrennt voneinander.

Ralf9 · 02 September 2015, 22:43:11

Zitat von: BrainHunter am 02 September 2015, 22:30:11
Das ist so irgendwie nicht ganz optimal.
Das der HM485d.pl einen Fork machen kann ist sicherlich sinnvoll, z.b. wenn man ihn ohne bind laufen lassen möchte. Das das ganze an --logfile gekoppelt ist, finde ich nicht sehr glücklich gelöst. Ich denke ein extra Schalter wäre hierfür passender. Dann funktioniert Beides auch getrennt voneinander.

Wird das fork überhaupt benötigt?
Wenn ich den HM485d.pl manuell im Hintergrund starten will, mache ich es mit &

Wenn ich es so starte, wird dann überhaupt ein fork benötigt?

Code Auswählen

./FHEM/lib/HM485/HM485d/HM485d.pl --serialNumber SGW0123456 --device /dev/ttyUSB0 --logfile ./log/HM485.log --verbose 4&

Gruß Ralf

geri · 03 September 2015, 10:29:33

Zitat von: Scotty80 am 02 September 2015, 22:09:02
bitte mal zum Verständnis: ist in der dev-Version 0.6.2 die Funktionalität des HMW-Sen-SC-12-Moduls schon voll implementiert?
Bzw. ab welcher für den Alltagsgebrauch geeigneten Version funktioniert dieses Modul?
Was ist der aktuelle STATE der Kanäle des Moduls? On und off? Open/Closed?

hi!

ich habe dieses modul auch schon länger im einsatz und hat eigentlich immer funktiniert. derzeit verwende ich die dev 0.7.21, dort funktioniert auch alles. das state ist "sensor_open" bzw. "sensor_closed".

für meinen einsatz ist die 0.7.21 alltagstauglich.

gruss
Gerald

BrainHunter · 03 September 2015, 13:15:08

Zitat von: Ralf9 am 02 September 2015, 22:43:11
Wird das fork überhaupt benötigt?
Wenn ich den HM485d.pl manuell im Hintergrund starten will, mache ich es mit &

Das ist schon ein kleiner Unterschied:
1. Wenn du ein Programm mit & startest ist es zwar im Hintergrund aber wenn du das Termainal Beendest / dich ausloggst wird ein SIGHUP an das Programm gesendet und es wird beendet.
2. Wenn du im Programm ein fork() machst und dann den Parent Prozess beendest wird als neuer Parent Prozess der Init Prozess verwendet. Jetzt ist es egal wenn du dich ausloggst der Prozess läuft weiter.

Das Problem im HM485d ist das die Serielle Schnittstelle vor dem fork geöffnet wird. Das Fork Kopiert jetzt den Prozess mitsammt der Datei Deskriptoren und dann wird der Prarent beendet. Beim Beenden wird jetzt noch versucht die Schnittstelle wieder zurückzustellen. (Macht das Perl automatisch? Oder kommt das aus der Implementierung vom HM485d/FHEM/...)
Ich denke wir haben hier im Prinzip 2 Möglichkeiten:
1. Das Fork an den anfang stellen.
2. Die Datei Deskriptoren der Serielle Schnittstelle (und evtl. auch des Netzwerk Socket) im Parent schließen bevor exit() aufgerufen wird.
Ersteres sollte einfacher sein