FHEM Forum

FHEM => Sonstiges => Thema gestartet von: vbs am 15 Mai 2014, 23:01:53

Titel: Serieller Port nach fork
Beitrag von: vbs am 15 Mai 2014, 23:01:53
Hi Ihr,

ich hab ein Problem, das ich seit einigen Tage untersuche, aber einfach keine Lösung finde. Ich habe ein fhem mit Modul TRX und XBMC laufen. TRX liest von einem Rfxtrx433 serielle Daten. Das ganze klappt problemlos bis das XBMC-Modul einen Prozess forkt und dieser sich beendet. Genau danach ist keine weitere Kommunikation mit dem seriellen Port mehr möglich.

Ich benutze TinyCore Linux 5.3 in einer VMWare unter Windows.

Ich hab mit strace herausgefunden, dass der forked-Prozess den seriellen Port komplett umkonfiguriert, wenn er sich beendet. Zum Testen hab ich ein kleines Perl-Script geschrieben, welches genau diese Situation nachstellt: COM-Port aufmachen und permanent vom Port lesen. Dann irgendwann einen fork aufmachen, der sich nach ein paar Sekunden beendet:
require Device::SerialPort;
my $po = new Device::SerialPort("/dev/ttyS0@38400");
die("could not open port") unless $po;

$po->reset_error();
      $po->baudrate(38400);
      $po->databits(8);
      $po->parity('none');
      $po->stopbits(1);
      $po->handshake('none');

      # This part is for some Linux kernel versions whih has strange default
      # settings.  Device::SerialPort is nice: if the flag is not defined for
      # your OS then it will be ignored.

      $po->stty_icanon(0);
      #$po->stty_parmrk(0); # The debian standard install does not have it
      $po->stty_icrnl(0);
      $po->stty_echoe(0);
      $po->stty_echok(0);
      $po->stty_echoctl(0);

      # Needed for some strange distros
      $po->stty_echo(0);
      $po->stty_icanon(0);
      $po->stty_isig(0);
      $po->stty_opost(0);
      $po->stty_icrnl(0);
   
    $po->write_settings;


my $i=0;
while(1) {
my $buf = $po->input();
    print "LEN: " . length($buf) . " :";
    (my $hex = unpack("H*", $buf)) =~ s/(..)/$1 /g;
    print $hex, "\n";
       
sleep 1;
$i = $i + 1;

if ($i == 7)
{
my $pid = fork();
if ($pid) {
print "I HAVE FORKED\n";
}
else
{
print "CHILD\n";
sleep 5;
print "EXIT\n";
exit(0);
}
    }
}

Auch damit kann ich das Problem nachstellen. Hat also nix mit fhem direkt zu tun. Zumindest kein offensichtlicher Bug in fhem.

Das ist die Ausgabe von strace, wenn sich der fork beendet:

...
...
...
[pid  4699] read(3, "", 255)            = 0
[pid  4699] time(NULL)                  = 1400151956
[pid  4699] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid  4699] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4699] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid  4699] nanosleep({1, 0},  <unfinished ...>
[pid  4701] <... nanosleep resumed> 0xbfc935ac) = 0
[pid  4701] time(NULL)                  = 1400151957
[pid  4701] ioctl(3, TCFLSH, 0x2)       = 0
[pid  4701] ioctl(3, SNDCTL_TMR_START or TCSETS, {B9600 opost isig icanon echo ...}) = 0
[pid  4701] close(3)                    = 0
[pid  4701] close(3)                    = -1 EBADF (Bad file descriptor)
[pid  4701] rt_sigaction(SIG_0, NULL, {SIG_DFL, ~[HUP INT ILL TRAP ABRT USR1 PIPE TERM STKFLT TSTP TTIN XCPU WINCH SYS RT_1 RT_2 RT_3 RT_5 RT_6 RT_9 RT_10 RT_12 RT_13 RT_14 RT_15 RT_17 RT_18 RT_20 RT_21 RT_22 RT_23 RT_24 RT_25 RT_26 RT_27 RT_29 RT_30 RT_31], SA_RESTORER|SA_RESTART|SA_INTERRUPT|SA_RESETHAND|0x37814c0, 0x804863e}, 8) = -1 EINVAL (Invalid argument)
[pid  4701] rt_sigaction(SIGHUP, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGINT, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGQUIT, NULL, {SIG_IGN, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGILL, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGTRAP, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGABRT, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGBUS, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGFPE, NULL, {SIG_IGN, [FPE], SA_RESTART}, 8) = 0
[pid  4701] rt_sigaction(SIGKILL, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGUSR1, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGSEGV, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGUSR2, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGPIPE, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGALRM, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGTERM, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGSTKFLT, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGCONT, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGSTOP, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGTSTP, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGTTIN, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGTTOU, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGURG, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGXCPU, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGXFSZ, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGVTALRM, NULL,  <unfinished ...>
[pid  4699] <... nanosleep resumed> 0xbfc935ac) = 0
[pid  4701] <... rt_sigaction resumed> {SIG_DFL, [], 0}, 8) = 0
[pid  4699] time( <unfinished ...>
[pid  4701] rt_sigaction(SIGPROF, NULL,  <unfinished ...>
[pid  4699] <... time resumed> NULL)    = 1400151957
[pid  4699] read(3,  <unfinished ...>
[pid  4701] <... rt_sigaction resumed> {SIG_DFL, [], 0}, 8) = 0
[pid  4699] <... read resumed> 0x8538220, 255) = -1 EAGAIN (Resource temporarily unavailable)
[pid  4701] rt_sigaction(SIGWINCH, NULL,  <unfinished ...>
[pid  4699] time( <unfinished ...>
[pid  4701] <... rt_sigaction resumed> {SIG_DFL, [], 0}, 8) = 0
[pid  4699] <... time resumed> NULL)    = 1400151957
[pid  4701] rt_sigaction(SIGIO, NULL,  <unfinished ...>
[pid  4699] rt_sigprocmask(SIG_BLOCK, [CHLD],  <unfinished ...>
[pid  4701] <... rt_sigaction resumed> {SIG_DFL, [], 0}, 8) = 0
[pid  4699] <... rt_sigprocmask resumed> [], 8) = 0
[pid  4701] rt_sigaction(SIGPWR, NULL,  <unfinished ...>
[pid  4699] rt_sigaction(SIGCHLD, NULL,  <unfinished ...>
[pid  4701] <... rt_sigaction resumed> {SIG_DFL, [], 0}, 8) = 0
[pid  4699] <... rt_sigaction resumed> {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGSYS, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4699] rt_sigprocmask(SIG_SETMASK, [],  <unfinished ...>
[pid  4701] rt_sigaction(SIGRT_2, NULL,  <unfinished ...>
[pid  4699] <... rt_sigprocmask resumed> NULL, 8) = 0
[pid  4701] <... rt_sigaction resumed> {SIG_DFL, [], 0}, 8) = 0
[pid  4699] nanosleep({1, 0},  <unfinished ...>
[pid  4701] rt_sigaction(SIGRT_3, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_4, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_5, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_6, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_7, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_8, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_9, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_10, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_11, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_12, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_13, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_14, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_15, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_16, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_17, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_18, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_19, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_20, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_21, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_22, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_23, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_24, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_25, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_26, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_27, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_28, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_29, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_30, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_31, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGRT_32, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGABRT, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGIO, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] rt_sigaction(SIGSYS, NULL, {SIG_DFL, [], 0}, 8) = 0
[pid  4701] write(1, "CHILD\nEXIT\n", 11CHILD
EXIT
) = 11
[pid  4701] exit_group(0)               = ?
Process 4701 detached
<... nanosleep resumed> {0, 974618004}) = ? ERESTART_RESTARTBLOCK (To be restarted)
--- SIGCHLD (Child exited) @ 0 (0) ---
restart_syscall(<... resuming interrupted call ...>) = 0
time(NULL)                              = 1400151958
read(3, 0x8538220, 2
...
...
...


Ich denke, in der Zeile konfiguriert der Fork den Port fälschlicherweise auf 9600 Baud, wenn er sich beendet:
[pid  4701] ioctl(3, SNDCTL_TMR_START or TCSETS, {B9600 opost isig icanon echo ...}) = 0

Das ganze kann ich auch auf der Shell mit stty nachvollziehen. Im "Gutfall" ist der COM-Port so konfiguriert:
speed 38400 baud;stty: /dev/ttyS0
line = 0;
intr = ^C; quit = ^\; erase = ^?; kill = ^U; eof = ^D; eol = <undef>; eol2 = <undef>; swtch = <undef>; start = ^Q; stop = ^S; susp = ^Z; rprnt = ^R; werase = ^W; lnext = ^V;
flush = ^O; min = 0; time = 0;
-parenb -parodd cs8 hupcl -cstopb cread clocal -crtscts
ignbrk -brkint -ignpar -parmrk -inpck -istrip -inlcr -igncr -icrnl -ixon -ixoff -iuclc -ixany -imaxbel -iutf8
-opost -olcuc -ocrnl onlcr -onocr -onlret -ofill -ofdel nl0 cr0 tab0 bs0 vt0 ff0
-isig -icanon -iexten -echo -echoe -echok -echonl -noflsh -xcase -tostop -echoprt -echoctl echoke


Nachdem der fork sich beendet hat, sieht der Port so aus:
speed 9600 baud;stty: /dev/ttyS0
line = 0;
intr = ^C; quit = ^\; erase = ^?; kill = ^U; eof = ^D; eol = <undef>; eol2 = <undef>; swtch = <undef>; start = ^Q; stop = ^S; susp = ^Z; rprnt = ^R; werase = ^W; lnext = ^V;
flush = ^O; min = 1; time = 0;
-parenb -parodd cs8 hupcl -cstopb cread clocal -crtscts
-ignbrk -brkint -ignpar -parmrk -inpck -istrip -inlcr -igncr icrnl ixon -ixoff -iuclc -ixany -imaxbel -iutf8
opost -olcuc -ocrnl onlcr -onocr -onlret -ofill -ofdel nl0 cr0 tab0 bs0 vt0 ff0
isig icanon iexten echo echoe echok -echonl -noflsh -xcase -tostop -echoprt echoctl echoke


Seltsam ist außerdem, dass das nicht immer auftritt. In manchen Fällen konfiguriert der fork den Port wieder auf korrekte Settings. Ist sehr seltsam.

Ich bin im Moment total überfragt. Ich kann nicht sagen, ob es sich um ein VMware-, Perl-, TinyCore- oder Linux-Problem (oder was ganz anderes) handelt :(
Fällt da irgendjemandem etwas zu sein? Wäre super... Ich fummel schon seit Tagen an dem Problem rum und finde einfach keine Lösung, bin leicht verzweifelt :(

Danke!
Titel: Antw:Serieller Port nach fork
Beitrag von: rudolfkoenig am 16 Mai 2014, 09:15:21
Manche Linux Varianten kommen seit ca 3-4 Jahren auf die glorreiche Idee, die Parameter einer seriellen Schnittstelle bei close() zurueckzusetzen, auch wenn noch weitere Prozesse diese Schnittstelle offen haben. Aus diesem Grund musste ich das Parsen der config-Datei in FHEM umschreiben.

Ich vermute dass das XBMC Modul nach dem fork Schnittstellen nicht schliesst, was zu reparieren waere. Wie man das macht steht im FHEM/Blocking.pm sie Kommantar "# Close all kind of FD"
Titel: Antw:Serieller Port nach fork
Beitrag von: vbs am 16 Mai 2014, 18:30:07
Danke! Danke! Läuft jetzt nachdem ich den Port wie beschrieben geschlossen habe!!