Erstellt vor 4 Jahren

Geschlossen vor 3 Jahren

#2665 closed defect (fixed)

Aus der rc.custom starten Prozesse nicht mit '&'

Erstellt von: KingTutt Verantwortlicher: er13
Priorität: normal Meilenstein: freetz-next
Komponente: patches Version: devel
Stichworte: Beobachter:
Product Id: Firmware Version: all boxes/firmwares with wrapper filesystem

Beschreibung (zuletzt geändert von Whoopie)

In der rc.custom lege ich eine Datei mit echo > /var/tmp/ "…" an, setzte Ausführungsrechte mit chmod +x und starte sie zuletzt mit '&' am Ende.

Damit sollte ein neuer Prozesse getrennt von der rc.custom gestartet werden. Der Prozess wird aber nicht gestartet. Lässt man das '&' am Ende weg, wird der Prozess ausgeführt, die rc.custom terminiert jedoch nicht.

Hier der Inhalt der rc.custom:

echo >/var/tmp/events2syslog "
touch /var/tmp/eventsdump-old.log
while [ 1 == 1 ]
do
eventsdump | awk '{ print substr(\$0,0,13)\"X:XX\"substr(\$0,18)}' > /var/tmp/eventsdump.log
diff -a /var/tmp/eventsdump-old.log /var/tmp/eventsdump.log | sed -ne 's/^+\([0-9].*\)$/\1/pg' | sed -n '1!G;h;\$p' | logger \$1
mv /var/tmp/eventsdump.log /var/tmp/eventsdump-old.log
sleep 900
done
"
chmod +x /var/tmp/events2syslog
/var/tmp/events2syslog &


Von der Kommandozeile via Telnet startet das Script ohne Probleme mit '&'. Getestet mit freetz-devel-12884

Die .config hänge ich an.

IPPF Thread: http://www.ip-phone-forum.de/showthread.php?t=275653

Anhänge (3)

.config (59.9 KB) - hinzugefügt von KingTutt vor 4 Jahren.
strace.log (65.2 KB) - hinzugefügt von KingTutt vor 3 Jahren.
Erstellt mit FW 113.06.24-freetz-devel-12954
strace-04032015.log (65.8 KB) - hinzugefügt von KingTutt vor 3 Jahren.
Erstellt mit FW 113.06.24-freetz-devel-12987

Alle Anhänge herunterladen als: .zip

Änderungshistorie (43)

Geändert vor 4 Jahren durch KingTutt

comment:1 Antwort: Geändert vor 4 Jahren durch Whoopie

Hast Du auch exec /var/tmp/events2syslog ausprobiert?

Vielleicht solltest Du dem Skript auch ein Shebang #!/bin/sh geben.

Zuletzt geändert vor 4 Jahren von Whoopie (vorher) (Diff)

comment:2 als Antwort auf: ↑ 1 Geändert vor 4 Jahren durch KingTutt

Replying to Whoopie:

Hast Du auch exec /var/tmp/events2syslog ausprobiert?

Vielleicht solltest Du dem Skript auch ein Shebang #!/bin/sh geben.

Ich für den Tip, habe gerade beides ausprobiert. Das Ergebnis:

  • Das Hinzufügen eines Shebang bringt keine Änderung (das Script wird nicht gestartet)
  • Der Start via "exec" funktioniert, allerdings nur, wenn danach kein '&' steht, andernfalls startet das Script wieder nicht

Ergo: Ich habe damit zwar erst einmal eine Lösung (Danke dafür), allerdings sollte der Start eines Scriptes auch mit '&' funktionieren.
Falls der Weg mit dem "exec" der intendierte ist, kann ein Dev hier zu machen.

comment:3 Geändert vor 4 Jahren durch PeterPawn

@KingTutt:

Du hast nicht zufällig noch irgendwo eine abweichende umask gesetzt?

Die Syntax "+x" meint eigentlich "a+x", allerdings werden dabei Bits, die in umask gesetzt sind, nicht berücksichtigt. Eine umask von 133 (entspricht 644 als file-mode) würde also bei diesem Aufruf das x-Flag gar nicht setzen und dann ist es auch egal, ob da ein SheBang drin steht oder nicht. Die beschriebenen Symptome passen jedenfalls dazu, der entsprechende Test ist mit "a+x" anstelle des "+x" ja auch nicht weiter kompliziert.

comment:4 Geändert vor 4 Jahren durch Whoopie

Ich würde bei chmod immer mit Zahlen arbeiten, also chmod 755 /var/tmp/events2syslog.

comment:5 Geändert vor 4 Jahren durch Whoopie

  • Beschreibung geändert (Diff)

comment:6 Geändert vor 4 Jahren durch oliver

Wenn der Bootprozess nicht fertig wird, dann sind nicht alle Filedescriptors korrekt geschlossen.

Zu dem Problem mit dem Hintergrund: der Bootprozess läuft weiter und killt den Prozess im Hintergrund, wenn er selbst fertig ist. Es gibt ein busybox applet um wirklich im Hintergrund ohne Verbindung zum Parent zu starten. Der Name ist mit gerade entfallen.

comment:7 Geändert vor 4 Jahren durch ralf

@oliver
Du meinst vermutlich nohop.

Wo werden denn die Hintergrundprozesse gestoppt?

@KingTutt
Starte das Skript mal mit

sh -x /var/tmp/events2syslog &> /var/tmp/start.log &

Damit sollte in der Datei /var/tmp/start.log festgehalten werden, welche Kommandos ausgeführt werden.

Wenn Du strace auf die Box bringst, kannst Du auch dieses Kommando verwenden:

strace -f -o /var/tmp/strace.log sh /var/tmp/events2syslog &

comment:8 Antwort: Geändert vor 4 Jahren durch KingTutt

@PeterPan

AFAIK habe ich die umask nicht (nirgends bewusst) geändert. Bei einem ls -l /var/tmp/events2syslog via Telnet wirden die gesetzten Bits auch korrekt angezeigt. Wie auch immer ich habe eben beide Varianten probiert, einmal chmod a+x /var/tmp/events2syslog und einmal chmod 755 /var/tmp/events2syslog . In beiden Fällen ist das Resultat identisch. Das script läuft nicht mehr wenn ich mich per Telnet einlogge und nachsehe.

Die weitere Analyse von oliver scheint zutreffend zu sein. Ich kann nach dem Bootprozess via Telnet feststellen, dass die Datei /var/tmp/eventsdump-old.log angelegt wurde und 0 Byte groß ist.

/var/tmp/events2syslog muss also zumindest einmal gestartet worden sein und bis zum touch Befehl gekommen sein. Da es die Datei /var/tmp/eventsdump.log hingegen nicht gibt, ist das Script vor der Zeile mit dem eventsdump terminiert worden, entweder weil der Bootprozess es gekillt hat, oder weil die Zeile selbst einen Fehler verursacht hat. Letzteres würde ich ausschließen wollen, denn dann würde es auch mit einem exec nicht klappen.

Nachtrag:

@ralf

Ein start mit sh -x /var/tmp/events2syslog &> /var/tmp/start.log & hat folgenden output:

+ touch /var/tmp/eventsdump-old.log
+ [ 1 == 1 ]
+ eventsdump
+ awk { print substr($0,0,13)"X:XX"substr($0,18)}
+ sed -n 1!G;h;$p
+ sed -ne s/^+\([0-9].*\)$/\1/pg
+ diff -a /var/tmp/eventsdump-old.log /var/tmp/eventsdump.log
+ logger
+ mv /var/tmp/eventsdump.log /var/tmp/eventsdump-old.log
+ sleep 900

Um das ganze noch einmal mit strace zu versuchen müsste ich zunächst ein neues Image bauen und per remote flashen. In Anbetracht der Tatsache, dass ich derzeit kein Fallback Gateway habe und somit ein Produktivsystem lahmlegen könnte, mag ich das derzeit aber nicht probieren…

Zuletzt geändert vor 4 Jahren von KingTutt (vorher) (Diff)

comment:9 Geändert vor 4 Jahren durch oliver

Nein, nohup reicht nicht aus. Es war Start stop daemon.

comment:10 Geändert vor 4 Jahren durch PeterPawn

Ok, dann sollte man vielleicht mal zwischen zwei verschiedenen Problemen unterscheiden und den Titel des Tickets auch entsprechend anpassen.

Wenn ein Skript tatsächlich nicht gestartet wird, kann es an den Rechten liegen. Wenn es startet und abgebrochen wird, natürlich nicht.

Wenn Prozesse gestartet werden, dann ist der Titel irreführend, da sie lediglich beim Beenden ihres Parent-Prozesses dann ebenfalls den Heldentod sterben. Abhilfen (nohup und delay) wurden m.W. im verlinkten IPPF-Thread ausreichend erläutert. Beim Einsatz von "nohup" ist dann lediglich noch zu berücksichtigen, daß die Standard-FDs umgeleitet werden sollten, sonst kann es u.U. zu einem "Hängenbleiben" des Parent-Prozesses kommen (sprich: die Signalisierung von STOP an solche nohup-Childs erfolgt ja nicht und der Parent wartet sich einen Wolf auf diesen Kindprozess, wenn da noch Files geshared sind).

Durch den Start der rc.custom in rc.mod mit folgender Zeile:

sh /tmp/flash/mod/rc.custom 0</dev/null 1>/var/log/rc_custom.log 2>&1

erbt jedes aus der rc.custom gestartete weitere Skript genau diese Einstellungen ebenfalls, es wird also immer mit

/proc/self/fd/0 -> /dev/null
/proc/self/fd/1 -> pipe:[nnnn]
/proc/self/fd/2 -> /var/log/rc_custom.log

aufgerufen, was letztendlich auch der Grund für eine leere oder unvollständige rc_custom.log-Datei im Freetz-Webinterface ist, wenn man externe Kommandos ohne entsprechende Redirections aufruft aus der rc.custom.

Wenn man also neben ein asynchron laufendes Skript, das auch noch länger laufen soll, als der aufrufende Prozess läuft, mit "nohup" starten will, sollte man es nicht versäumen, die Standard-FDs entsprechend umzuleiten. Wenn ansonsten ein Parent-Prozess (SSH macht das gerne mal) erst terminiert, wenn die Standard-FDs ge"flush"ed wurden und dort EOF signalisiert wird, dann bleibt dieser Prozess solange hängen, bis tatsächlich alle Referenzen auf dieses File geschlossen sind, vorher gibt es kein EOF.

Wie AVM selbst das macht, kann man in der rc.tail.sh anhand des Aufrufs von "set_modulemem" sehen, da wird aber auch nicht "außen herum" schon alles "redirected" (also rc.tail.sh selbst läuft ohne Redirections für fd 0-2).

Theoretisch "stirbt" aber der Parent-Prozess tatsächlich erst am Ende des init-Prozesses (nach dem Ende der Abarbeitung von rc.S), es ist aber sicherlich nicht zielführend, diesen Prozess wesentlich länger am Leben zu erhalten. Wenn man wirklich asynchrone Prozesse starten will, gibt es dafür start-stop-daemon mit b-Option. Wenn man also eine passende Busybox hat (oder man nimmt eben nohup, wie AVM, denn da fehlt start-stop-daemon auch), ist das der sauberste Weg. Ansonsten bleibt immer noch das "delay -d 0 MYID command", was auch - ohne weitere Verzögerungen - einen "detached process" startet (durch den multid, der muß also schon laufen), einzige Einschränkung ist die Anforderung, daß MYID eindeutig sein muß.

Bei vielen anderen Formen riskiert man die Unterbrechung des init-Prozesses (zwar im fortgeschrittenen Stadium, aber durchaus noch lange vor der external-Verarbeitung) … ich mach' mal ein Beispiel, das kommt in Kürze im IPPF-Thread, denn Diskussionen sollten ja dort stattfinden.

Zuletzt geändert vor 4 Jahren von PeterPawn (vorher) (Diff)

comment:11 als Antwort auf: ↑ 8 Geändert vor 4 Jahren durch ralf

Replying to KingTutt:

Um das ganze noch einmal mit strace zu versuchen müsste ich zunächst ein neues Image bauen und per remote flashen.

Nicht unbedingt, Du kannst strace auch auf einem USB-Speicher ablegen oder von einem Web-Server herunterladen.

comment:12 Geändert vor 4 Jahren durch PeterPawn

Eine weitere Möglichkeit, bei eigener Busybox einen "detached process" zu starten, ist die Verwendung des Busybox-Applets chpst, das sich hinter "Runit …" versteckt in der Busybox-Konfiguration.

Unter bestimmten Umständen (der gestartete Prozess benötigt einige Standard-FDs nicht bzw. soll in seiner Ressourcennutzung limitiert werden oder soll in einem chroot-Jail laufen) ist das besser einzusetzen, als start-stop-daemon … es stammt zwar aus "demselben Thema" in der Busybox, aber hat eben einige zusätzliche Goodies ggü. start-stop-daemon.

comment:13 Geändert vor 4 Jahren durch er13

So wie ich das sehe, handelt es sich um keinen Bug, sondern um ein Feature. Zum einen werden die Prozesse gestartet. Das Verhalten, welches man als "nicht gestartet" wahrnimmt, ist darauf zurückzuführen, dass sobald der Parent beendet wird, werden auch die Kinder mit in den Tod gerissen. Mögliche Lösungen [brainstorming, Variante 2 nicht getestet]:

  • Man deklariert dieses Verhalten als Feature, dokumentiert alle möglichen Wege die Scripte aus rc.custom zu starten und schließt das Ticket.
  • Man startet rc.mod im detached-Mode. Würde es das Problem lösen oder müsste man die Kinder von rc.mod dann immer noch detachen?

Edit: irgendwo wurde behauptet, dass es früher mal funktioniert hat. Wenn dem so ist, würde mich interessieren, was nun dazu führt, dass es nicht mehr so ist. Irgendeine Busybox-Änderung oder hat AVM etwas in den Scripten geändert?

Zuletzt geändert vor 4 Jahren von er13 (vorher) (Diff)

comment:14 Geändert vor 3 Jahren durch KingTutt

@er13
funktioniert hatte das ganze mit '&' ohne Probleme auf einer 7390 mit FW 84.06.03-freetz-devel-12789. Ich glaube im oben genannten Forum finden sich auch Hinweise dazu.

Nach einem Wechsel auf die 7490 mit FW switch auf 06.23 funktionierte das Starten mit '&' dann nicht mehr.

ticket:2665#comment:7 folgend habe ich jetzt mit dem FW Update auf 113.06.24-freetz-devel-12954 auch noch einmal strace mit auf die Box gebracht. Ich hänge das logfile hier an, evtl. hilft das bei der Analyse etwas weiter.

Geändert vor 3 Jahren durch KingTutt

Erstellt mit FW 113.06.24-freetz-devel-12954

comment:15 Geändert vor 3 Jahren durch er13

In dem callmonitor-Thread wird berichtet, dass der Callmonitor beim Booten nicht automatisch startet, wohingegen wenn man ihn nach dem Booten übers Web-If bzw. im Terminal startet, funktioniert alles einwandfrei. Ich kann das Problem auf meiner Testbox nachstellen. Meine erste Analyse zeigt, es handelt sich dabei um denselben Bug wie der aus diesem Ticket (callmonitor-daemon ist ein Shell-Script).

comment:16 Antworten: Geändert vor 3 Jahren durch PeterPawn

Ich halte das derzeitige Verhalten für POSIX-konform, wenn man die Reihenfolge der Abläufe verfolgt. Der Parent-Prozess ist rc.S, wenn der beendet wird, erhalten die noch existierenden Childs ein SIGHUP und entscheiden ihrerseits durch die (Nicht-)Behandlung dieses Signals, was mit ihnen passiert.

Insofern wäre es (m.E.) eher die Frage, warum das vorher funktioniert hat … die einzige Erklärung, die ich bisher gefunden habe, ist das parallele Verwenden der (früheren) debug.cfg zum Starten von weiteren Prozessen und das auf eine Art und Weise, daß damit rc.S während der gesamten Laufzeit des Systems nicht beendet wurde, weil auf das Beenden dieser Childs gewartet wurde. Da bis zum Start von rc.custom alles andere nur ge"source"d ist, ist jede (auch unbeabsichtigte) Subshell ein Kandidat, auf deren Ende gewartet werden könnte.

Solange niemand mit einem solchen System mal eine Prozessliste nach dem Systemstart und die (bisher) verwendete debug.cfg veröffentlicht, kann man aber nur raten. Ich kann das Verhalten ohne aktivierten SIGHUP-Handler im Child-Prozess weder auf 7390 noch auf 7490 nachvollziehen. Die debug.cfg wäre dann der entscheidende Unterschied, der das geänderte Verhalten verursacht und kein Unterschied in den Kernel-Versionen oder FRITZBox-Modellen.

Wenn es um ein einheitliches Verhalten geht, wäre eine ordentliche Dokumentation, welche Voraussetzungen/Schritte ein funktionierender asynchroner Prozess erfüllen/vollziehen muß, damit er das Ende des Systemstarts überlebt, m.E. der bessere Weg (also ein neues Template/neue Kommentare für rc.custom). Wenn dabei gleich noch die richtige Behandlung der Standard-FDs erläutert wird, macht die rc_custom.log am Ende auch wieder Sinn … im Moment schreibt jeder dort asynchron gestartete Prozess seinerseits eine neue rc_custom.log-Datei, weil er die Descriptoren aus rc.mod erbt.

Vermutlich hat es ja historische Gründe, warum von Freetz nicht die Tools im "Runit"-Zweig der Busybox für die Steuerung von Services/Daemons verwendet werden. Wenn sie aber vorhanden sind, erleichtern sie die Konstruktion von so ziemlich jedem denkbaren Fall eines solchen Dienstes, von Protokollierung über Pre-/Post-Behandlung bis automatischem Restart nach Abbruch. Da wäre dann wieder die Frage, wie man mit der Rückwärtskompatibilität umgehen will, denn die runit-Utilities tragen mit unkomprimierten 24 KByte (ohne setuidgid, envuidgid und softlimit) auf und die sind ja auf einer Box mit 3,6875 MB Filesystem-Flash schon nicht unerheblich. Andererseits können sie den Nutzern das Schreiben von eigenen Services so weit erleichtern (und es vereinheitlichen), daß sich eine Überlegung in diese Richtung schon lohnen würde.

comment:17 als Antwort auf: ↑ 16 Geändert vor 3 Jahren durch er13

Replying to PeterPawn:

rc.S während der gesamten Laufzeit des Systems nicht beendet wurde

Kann ich definitiv ausschließen - auf keiner der Boxen (in der Familie, im Freundeskreis), die ich betreue, läuft rc.S (habe gerade extra gecheckt). Und es sind unterschiedlichste Boxen dabei: 04.xx, 05.2x, 06.0x.

comment:18 Antwort: Geändert vor 3 Jahren durch PeterPawn

@er13:

Hast Du denn auf diesen Boxen die debug.cfg und die rc.custom parallel im Einsatz und startest Du von dort auch eigene Skripte (abseits von "regulären" Freetz-Paketen), die dann auch das Ende des Systemstarts überleben (sollen)?

Ansonsten bist Du doch in der Lage, von diesen Boxen die Prozessliste zu ziehen, damit man mal sehen kann, was da Sache ist. Irgendjemand muß dann ja das SIGHUP beim Beenden von rc.S "konsumiert" haben, denn der Default-Handler würde (nach allem, was ich in BB 1.22 gesehen hatte) den Prozess abbrechen. Wenn die gestarteten Tasks alle am Ende 1 als Parent haben, muß die ja irgendjemand umgekettet haben und das passiert im exit4 für den Parentprozess im Kernel, wenn der Prozess auf SIGHUP nicht abgebrochen wurde.

Ich habe gerade festgestellt, daß das letzte, was ich im IPPF in dem o.a. Thread geschrieben hatte, nicht  mehr da ist … ich hatte mal das Exit-Handling und die Behandlung von orphaned childs in den Kernelquellen nachgeschlagen, nachdem mich Ralf darauf gestoßen hatte, daß das ganz POSIX-gemäß alles im exit-Syscall erfolgt und die StdLib damit wenig bis nichts zu tun hat.

comment:19 als Antwort auf: ↑ 18 ; Antwort: Geändert vor 3 Jahren durch er13

Replying to PeterPawn:

Irgendjemand muß dann ja das SIGHUP beim Beenden von rc.S "konsumiert" haben

Wie stellt man denn fest, wer es konsumuert hat?

denn der Default-Handler würde (nach allem, was ich in BB 1.22 gesehen hatte) den Prozess abbrechen. Wenn die gestarteten Tasks alle am Ende 1 als Parent haben, muß die ja irgendjemand umgekettet haben und das passiert im exit4 für den Parentprozess im Kernel, wenn der Prozess auf SIGHUP nicht abgebrochen wurde.

So sieht es aus auf einer 7170 (ist nicht vom Problem betroffen):

  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
 2912  2699 root     R     1308   4%  39% {busybox} top
 1013     1 root     S N   9176  30%   0% /usr/bin/avm/ctlmgr
 1294  1013 root     S N   9176  30%   0% /usr/bin/avm/ctlmgr
 1295  1294 root     S N   9176  30%   0% /usr/bin/avm/ctlmgr
 1296  1294 root     S N   9176  30%   0% /usr/bin/avm/ctlmgr
 1357     1 root     S <   4848  16%   0% voipd
 1351     1 root     R     4428  15%   0% telefon a127.0.0.1
 1341     1 root     S     4356  14%   0% dsld -i -n
 1382     1 root     S     4324  14%   0% /bin/avmike
 1190     1 root     S     4120  14%   0% multid -t -d -i
 1263  1190 root     S     4120  14%   0% multid -t -d -i
 1018     1 root     S     3648  12%   0% upnpd
 1316  1315 root     S     3648  12%   0% upnpd
 1315  1018 root     S     3648  12%   0% upnpd
 1317  1315 root     S     3648  12%   0% upnpd
 1468     1 root     S     3600  12%   0% /usr/bin/faxd -a
 1362     1 root     S     3444  11%   0% pbd
 1369  1363 root     S     3444  11%   0% pbd
 1368  1363 root     S     3444  11%   0% pbd
 1363  1362 root     S     3444  11%   0% pbd
 3177     1 root     S     2024   7%   0% privoxy --pidfile /var/run/privoxy.pid /mod/etc/privoxy/config
 1241     1 root     S     1900   6%   0% wpa_authenticator
 1469  1013 root     S     1824   6%   0% capiotcp_server -p5031 -m99
 1838     1 root     S     1492   5%   0% {busybox} syslogd -L -C200
 2855  2791 root     S     1492   5%   0% {callmonitor} /bin/ash /usr/sbin/callmonitor
 2791     1 root     S     1492   5%   0% {callmonitor} /bin/ash /usr/sbin/callmonitor
 2853  2791 root     S     1492   5%   0% {callmonitor} /bin/ash /usr/sbin/callmonitor
 2851  2791 root     S     1492   5%   0% {callmonitor} /bin/ash /usr/sbin/callmonitor

Und so auf der Test-7490 (beide Ausgaben sind etwas gekürzt):

  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
 4369  3853 root     R     1352   1%  12% {busybox} top
 1086     1 root     S    18328   7%   0% /usr/bin/avm/ctlmgr
 1367     1 root     S    16860   7%   0% /usr/bin/aha
 1089     1 root     S    11432   5%   0% upnpd
 1288     1 root     S    10324   4%   0% pbd
 1300     1 root     S     7548   3%   0% telefon a127.0.0.1
 1310     1 root     S <   5788   2%   0% voipd
  980     1 root     S     5432   2%   0% dsl_monitor -d
 1166     1 root     S     4824   2%   0% upnpdevd
 1177     1 root     S     4392   2%   0% wland -B
 1249     1 root     S     4276   2%   0% dsld -i -n
 1132     1 root     S     3872   2%   0% multid
 1080     1 root     S     3132   1%   0% l2tpv3d
 1076     1 root     S     2592   1%   0% avmipcd
  896     1 root     S     2364   1%   0% /bin/configd
 1724     1 root     S     1596   1%   0% {busybox} syslogd -L -C256
 3852  1828 root     S     1476   1%   0% dropbear -p 22 -0
 1828     1 root     S     1432   1%   0% dropbear -p 22 -0
  685     1 root     S     1348   1%   0% {busybox} tail -f /nohup.out
 1563     1 root     S     1348   1%   0% {busybox} crond -b
 1726     1 root     S     1344   1%   0% /sbin/klogd -c 4
 1660     1 root     S     1344   1%   0% {busybox} httpd-webcfg -P /var/run/webcfg.pid -p 81 -c /mod/etc/webcfg.conf -h /usr/mww/ -r Freetz
 1760     1 root     S     1344   1%   0% {busybox} inetd
 4367  3754 root     S     1340   1%   0% {busybox} sleep 60
    1     0 root     S     1312   1%   0% init
 2456     1 root     S     1312   1%   0% init
 1496     1 root     S     1272   1%   0% wpa_supplicant -g /var/run/wpa_supplicant/global -D athr
 1365     1 root     S     1260   1%   0% hostapd -g /var/run/hostapd/global
 2564  1132 root     S     1216   0%   0% /sbin/chronyd -n -f /var/tmp/chrony.conf
  680     1 root     S <   1056   0%   0% /sbin/udevd --daemon
 1351   680 root     S <   1056   0%   0% /sbin/udevd --daemon
 1330   680 root     S <   1056   0%   0% /sbin/udevd --daemon
 1389     1 root     S      928   0%   0% /bin/run_clock -c /dev/tffs -d

Mein Test-Case ist der Callmonitor. Läuft auf der 7170 mit dem Parent 1, startet auf der 7490 und läuft noch einige Zeit danach. Zum Zeitpunkt, wo ich im Web-If anmelde, ist er aber tot.

Zum ersten Mal wurde das Problem irgendwann mal im September 2014 erwähnt. Zeitlich würde es zu 6.0x → 6.2x passen. Ich habe 6.0x/etc mit 6.2x/etc verglichen und habe außer neu hinzugekommenen (in /etc/init.d/S01-head)

## Set max-Stacksize to 512kB for init shell
ulimit -s 512

finden können. Daran liegt es nicht, habe ich getestet.

comment:20 als Antwort auf: ↑ 19 ; Antwort: Geändert vor 3 Jahren durch PeterPawn

Replying to er13:

Wie stellt man denn fest, wer es konsumuert hat?

Dazu habe ich auch keine Idee, ist ein wenig Schroedinger an dieser Stelle. Richtet man einen eigenen Handler ein, konsumiert der, denn es ist leider nicht wie mit Exceptions, die man erneut per throw auslösen kann (jedenfalls wüßte ich nicht wie, bei Exceptions läuft das mit Stack-Unwinds, bei Signals kenne ich kein "Daisy-Chaining").

Welche Busybox-Version kommt denn auf der alten 7170 zum Einsatz? Auf der 7490 würde ich die neueste (1.23) annehmen, wobei das mit 1.22.1 auch schon gemeldet wurde, bei der 1.22.0 bin ich da nicht so sicher.

Ich hatte die BB-Version bisher eigentlich als Quelle ausgeschlossen, da es einen Bericht gab (von KingTutt, wenn ich mich recht erinnere), daß es mit 1.22.1 auf 7390 klappt (asynchroner Prozess überlebt), während es auf 7490 abbricht (m.E. die richtige Reaktion).

Da fiel mir auch nur noch die unterschiedliche Kernel-Version ein … wenn man sich mal die "exit.c" aus dem 2.6.28 und aus dem 2.6.32 ansieht (speziell __set_special_pids und reparent_thread), dann findet man auch eine abweichende Behandlung - zwischen 2.6.28 und 2.6.32 war das Verhalten des exit-Syscalls wohl doch nicht ganz so konsistent, wie man das bei einer so essentiellen Schnittstelle annehmen würde. Die Lektüre eines Diffs dieser beiden Dateien würde ich jedem C-Programmierer bei der Suche nach einer Erklärung für das Phänomen ans Herz legen.

Denn wenn man dann in 2.6.28 findet, daß dort in __set_special_pids eben auch die session und die pgrp neu gesetzt wurden, was in 2.6.32 nicht mehr der Fall ist, dann könnte das schon ein entscheidender Unterschied sein (wird von "daemonize" aufgerufen) - Stichwort "Group-Leader oder nicht". Eigentlich ist wieder "daemonize" aber nur Hilfsfunktion für Kernel-Threads und dürfte mit "normalen" Userspace-Daemons überhaupt nicht in Berührung kommen.

Aber auch die "reparent_thread"-Funktion hat eben eine erheblich andere Programmlogik erhalten irgendwo auf dem Weg von der einen zur anderen Version (in der Gegend von "do_notify_parent" und mit dem Abbruch des "reparenting", wenn "task_detached" zutrifft, ziemlich am Beginn).

Welcher konkrete Unterschied nun zu dem abweichenden Verhalten führt, ist mir ohne Kernel-Debugging ein Rätsel … und es ist eigentlich auch egal.

Das wäre dann eben nicht von der Version der Firmware abhängig, denn m.W. hat sich ja bei keiner Box mit der neuen 06.2x-Reihe die zugrundeliegende Kernelversion geändert. Das wiederum widerspricht dann den Berichten, wonach es von der Firmware-Version abhängig ist und nur für solche Fälle hatte ich mir die Erklärung mit der debug.cfg zurechtgelegt - quasi zwei verschiedene Ursachen mit demselben Ergebnis, die auch losgelöst voneinander auftreten können.

Es bleibt für mich dabei: Wenn man eine einheitliche Vorgehensweise über alle Versionen/Modelle/Kernel will, muß man das auf POSIX-konforme Weise erledigen und da ist das korrekte Verhalten beim exit() genau beschrieben. So verhält sich die 7490 nach meinem Test und - das ist ja wieder das Merkwürdige, weshalb ich dann auch aufgab - bei mir eben auch die 7390 mit 06.2x (ob x jetzt 0,1 oder 3 war, weiß ich nicht mehr, ist schon wieder einen Monat her) - was die Theorie mit der Kernelversion eigentlich wieder über den Haufen warf.

Da es mir am Ende aber auch Bummi ist, warum es anders reagiert, habe ich das dann verworfen und mich einfach auf die schon mal erwähnten runit-Utilities der Busybox gestürzt, die das alles mehr oder weniger alleine regeln können und wo man sich auch bei 2.6.28 oder Busybox 1.20.x im AVM-Image keinen Kopf machen muß.

comment:21 als Antwort auf: ↑ 16 Geändert vor 3 Jahren durch ralf

Replying to PeterPawn:

Insofern wäre es (m.E.) eher die Frage, warum das vorher funktioniert hat … die einzige Erklärung, die ich bisher gefunden habe, ist das parallele Verwenden der (früheren) debug.cfg zum Starten von weiteren Prozessen und das auf eine Art und Weise, daß damit rc.S während der gesamten Laufzeit des Systems nicht beendet wurde, weil auf das Beenden dieser Childs gewartet wurde. Da bis zum Start von rc.custom alles andere nur ge"source"d ist, ist jede (auch unbeabsichtigte) Subshell ein Kandidat, auf deren Ende gewartet werden könnte.

Der Grund, warum es vorher funktioniert hat, ist vermutlich, dass etwas am init Prozess der Busybox geändert wurde. Ich kann mich dunkel erinnern, dass es dazu mal eine Diskussion auf der Busybox Liste gab, gehen wir also mal davon aus, dass irgendwann etwas geändert wurde und es mit älteren Versionen funktioniert hat und mit neueren nicht mehr.
Ich gehe davon aus, dass init inzwischen setsid aufruft, im Gegensatz zu früher. Der Vorteil mit setsid ist, dass man mit setsid in der Shell Job Control hat. Man kann also mit Ctrl-C oder Ctrl-Z Prozesse abbrechen oder anhalten. Das geht sonst nicht. Der Nachteil ist die hier besprochene Problematik.

Zwischen debug.cfg und rc.custom gibt es keinen prinzipiellen Unterschied, beide werden von rc.S über source eingelesen, wenn auch offensichtlich nicht gleichzeitig und mit einigen anderen Kommandos dazwischen. Ebenfalls ist es Fehler, wenn in debug.cfg oder rc.custom etwas steht was dazu führt, dass rc.S nicht beendet wird. Dann wird init nicht richtig initialisiert zumindest in früheren Versionen, was dazu führt, dass über kurz oder lang die Box nicht mehr funktioniert.

comment:22 Geändert vor 3 Jahren durch PeterPawn

@ralf:

Irgendwann müsste man sich aber mal einigen, was denn nun die Ursache sein kann - vielleicht habe ich die Diskussion im Thread ja tatsächlich total mißverstanden. Aber die von Dir beschriebene Diskussion auf der BB-Mailingliste erklärt ja dann wieder nicht, wieso es bei identischer Busybox-Version auf unterschiedlichen Modellen auch ein anderes Verhalten gibt. Oder was sehe ich da nicht? Ich gehe nach wie vor von einer Kombination mehrerer Faktoren aus, da keine der bisher geäußerten Theorien die beschriebenen Symptome in ihrer Gesamtheit erklären kann.

comment:23 als Antwort auf: ↑ 20 Geändert vor 3 Jahren durch er13

Replying to PeterPawn:

Welche Busybox-Version kommt denn auf der alten 7170 zum Einsatz? Auf der 7490 würde ich die neueste (1.23) annehmen, wobei das mit 1.22.1 auch schon gemeldet wurde, bei der 1.22.0 bin ich da nicht so sicher.

Auf beiden Boxen ist 1.23.1 im Einsatz. Im busybox-init-Changelog (1.23.x) finde ich nichts verdächtiges, wobei nur die letzten 3 Commits in 1.23.x neu hinzugekommen sind (man vergleiche mit busybox-init-Changelog (1.22.x)). Das Ticket wurde noch zu der Zeit aufgemacht, zu der wir noch 1.22.x hatten (s. #2672). Damit würde ich busybox mit sehr großer Wahrscheinlichkeit ausschließen wollen.

comment:24 Geändert vor 3 Jahren durch er13

Könnte bitte jemand mit einer 7390 eine Aussage zu 06.2x machen. Hier wird behauptet (Zitat) "Auf meiner 7390 läuft die rc.custom auch heute noch wie gewohnt", und hier dann nochmal extra bestätigt.

comment:25 Geändert vor 3 Jahren durch PeterPawn

Das kann ich aus eigenem Test dahingehend klarstellen, daß in der rc.custom ohne SigHandler gestartete Prozesse zwar noch den Start der gesamten external-Verarbeitung überleben (so man denn eine hat), aber beim Beenden von rc.S, das ja erst nach diesen ganzen Aktionen erfolgt (ggf. noch mit Warten auf Uhrzeitsynchronisation vor dem Start der "externals"), wurden solche Tasks bei mir sauber "abgeschossen" (ich hatte mit logger jeweils in sleep-Loops protokolliert). Das war auch der Grund, warum ich die Behauptung, "bei der 7390 lief es noch" nicht verifizieren konnte. Wenn rc.S zum Ende kam (was z.B. bei einem wait für ein Child ja nicht der Fall ist, wenn dieser Prozess nicht terminiert), gehen auch die "orphaned childs" dahin, wenn sie keine entsprechende Vorsorge treffen.

Bei diesen Tests fiel es dann auch auf (ls -la /proc/self/fd), daß alle dort gestarteten Prozesse eine "frische Instanz" der rc_custom.log erbten.

comment:26 Geändert vor 3 Jahren durch er13

Ich habe mir dem folgenden Programmchen die Season-Leader-ID in rc.custom ausgeben lassen:

#include <stdio.h>
#include <unistd.h>
#include <sys/types.h>

#define _GNU_SOURCE

int main(int argc, char **argv) {
	printf("[caller] session leader id: %d, process group id: %d / [callee] session leader id: %d, process group id: %d\n", getsid(0), getpgid(0), getsid(getpid()), getpgid(getpid()));
	return 0;
}

So sieht die Ausgabe auf der 7490:

[caller] session leader id: 149, process group id: 149 / [callee] session leader id: 149, process group id: 149
 S   UID   PID  PPID   VSZ   RSS TTY   STIME TIME     CMD
 S     0     1     0  1312   380 0:0   00:59 00:00:05 init
 S     0   149     1  1592   792 ttyS0 01:00 00:00:00 {rc.S} /bin/sh /etc/init.

Und so auf der 7170:

[caller] session leader id: 97, process group id: 97 / [callee] session leader id: 97, process group id: 97
 S   UID   PID  PPID   VSZ   RSS TTY   STIME TIME     CMD
 S     0     1     0  1300   388 0:0   01:04 00:00:02 init
 S     0    97     1  1532   812 0:0   01:04 00:00:01 {rc.S} /bin/sh /etc/init.

Wie man sieht, ist rc.S in beiden Fällen der Session-Leader. Was mir dabei eher zufällig aufgefallen ist, ist die Spalte TTY. Ich hätte nämlich erwartet, dass init und damit auch rc.S ohne controlling TTY gestartet werden (s. patches/scripts/102-add_inittab.sh#L19). Auf der 7490 bekommt rc.S aber auf einmal ttyS0 als controlling TTY.

Ich habe, Peter, Dein Script aus diesem Post auf beiden Boxen eingebaut und festgestellt, dass das SIGHUP auf der 7170 nie ankommt.

7170:
[2587] is looping, count = 12, [caller] session leader id: 97, process group id: 97 / [callee] session leader id: 97, process group id: 97
[2587] Trap EXIT received for 2587

vs.

7490:
[2276] Trap HUP received for 2276
[2276] is looping, count = 2, [caller] session leader id: 149, process group id: 149 / [callee] session leader id: 149, process group id: 149
[2276] is looping, count = 12, [caller] session leader id: 149, process group id: 149 / [callee] session leader id: 149, process group id: 149
[2276] Trap EXIT received for 2276

Ist es nicht so, dass die Signale an die (Group-)Kinder nur dann geschickt werden, wenn die noch ein controlling TTY haben? Im umgekehrten Fall passiert es nicht auch wenn sie sich noch in der Group befinden. Habe leider auf die schnelle noch nichts dazu googlen können (dies zählt noch nicht).

Wenn meine Vermutung richtig ist, wäre es der erste Schritt in Richtung mögliche Erklärung. Die Frage wäre dann, was führt dazu, dass rc.S ein controlling TTY gesetzt bekommt.

comment:27 Antwort: Geändert vor 3 Jahren durch PeterPawn

Das wäre dann nur eine einzige Zeile in der /etc/inittab. Die erste Spalte eines Eintrags legt das CTTY fest.

EDIT:

Offenbar wird das in Freetz ja anders behandelt als bei AVM, weil /dev/ttyS0 durch irgendeinen Patch entfernt werden könnte. In diesem Falle könnte man versuchen, ob die Syntax mit dem "dash" für die Zuordnung eines CTTY vor dem Programmnamen auch Abhilfe schafft bei rc.S.

Im Moment wird das ja nur für die "askfirst"-Zeile entsprechend geändert (die m.E. bei nicht vorhandener "serial console" auch komplett raus könnte - wo sollte die Console sonst laufen?).

Wenn FREETZ_DISABLE_SERIAL_CONSOLE nicht aktiv ist, kann ja direkt "$console" im "cat" vor der rc.S-Zeile angegeben werden.

Zuletzt geändert vor 3 Jahren von PeterPawn (vorher) (Diff)

comment:28 als Antwort auf: ↑ 27 Geändert vor 3 Jahren durch er13

Replying to PeterPawn:

In diesem Falle könnte man versuchen, ob die Syntax mit dem "dash" für die Zuordnung eines CTTY vor dem Programmnamen auch Abhilfe schafft bei rc.S.

Da kann ich Dir nicht ganz folgen. Ich will ja gerade das Verhalten "ohne CTTY" erzwingen, da hilft mir die dash-Syntax gar nicht. Außerdem ist es wie gesagt in Freetz schon jetzt auf no CTTY eingestellt, die Frage ist, wie kommt's, dass es trotz dieser Einstellung gesetzt wird.

Aber davor muss man klären, ob mein Verdacht, dass die Signals an die Kinder ohne CTTY nicht übermittelt werden, überhaupt richtig ist - uns zwar genau aus dem Grund, weil diese kein CTTY haben.

comment:29 Antwort: Geändert vor 3 Jahren durch PeterPawn

Ok, Richtung verwechselt, sorry … aber ich verstehe ohnehin nicht, warum man das jetzt unbedingt auf "kein CTTY" umbauen will.

Wenn auf der 7170 kein SIGHUP kommt, schadet es doch trotzdem nicht, wenn man eine "trap" dafür in seinem Skript einrichtet. Die wird halt nie aufgerufen, aber das stört ja nicht. Wenn es ein SIGHUP gibt - wie auf der 7490 - dann ignoriert man es eben und damit sollte - so war es bei meinem Test - das "reparent_thread" in exit.c die pgrp ordentlich an init anhängen, wo sie dann weiter laufen kann. Diese Variante ist doch dann unabhängig davon, ob die pgrp ein CTTY hat oder nicht.

Was verstehe ich in diesem Zusammenhang jetzt falsch?

Du willst doch den "callmonitor" zum Laufen bringen. Wenn Du dort in das aufgerufene Shell-Skript einen passenden trap-Handler aufnimmst, kannst Du das Signal meines Wissens praktisch "aussitzen" und wenn der Thread dann weiter am Leben ist nach dem Abschluß des Handlings, läuft er eben weiter.

comment:30 als Antwort auf: ↑ 29 ; Antwort: Geändert vor 3 Jahren durch ralf

Replying to PeterPawn:

Wenn auf der 7170 kein SIGHUP kommt, schadet es doch trotzdem nicht, wenn man eine "trap" dafür in seinem Skript einrichtet. Die wird halt nie aufgerufen, aber das stört ja nicht. Wenn es ein SIGHUP gibt - wie auf der 7490 - dann ignoriert man es eben und damit sollte - so war es bei meinem Test - das "reparent_thread" in exit.c die pgrp ordentlich an init anhängen, wo sie dann weiter laufen kann. Diese Variante ist doch dann unabhängig davon, ob die pgrp ein CTTY hat oder nicht.

Das ist sicherlich richtig.

Wenn man aber einfach sicherstellen kann, dass kein SUGHUP generiert wird, dann ist das einfacher, als in jedem Skript, einschließlich vom Benutzer erstellten, darauf zu achten, dass SIGHUP angefangen wird.

comment:31 als Antwort auf: ↑ 30 ; Antwort: Geändert vor 3 Jahren durch PeterPawn

Replying to ralf:

Das ist sicherlich richtig. Wenn man aber einfach sicherstellen kann, dass kein SUGHUP generiert wird, dann ist das einfacher, als in jedem Skript, einschließlich vom Benutzer erstellten, darauf zu achten, dass SIGHUP angefangen wird.

Das ist sicherlich auch richtig.

Aber es erhöht nach meiner Meinung die Konfusion, wenn sich ein Skript beim Start aus der rc.custom anders verhält, als wenn es aus einer anderen Umgebung (egal ob aus der debug.cfg bei AVM oder einer Telnet-Session) gestartet wird.

Sicherlich wird es auch immer wieder Situationen geben, wo man den gestarteten Prozess gar nicht beeinflussen kann (weil es z.B. kein Shell-Skript ist), aber dafür gibt es ja von außen die Möglichkeit, entsprechende Kommandos zu verwenden, die den Aufbau der Prozesshierarchie bereits beim Start entsprechend ändern und nicht erst als Ergebnis des Beendens des Parent-Prozesses (start-stop-daemon und chpst). Wenn man diese richtig einsetzt, muß man auch nicht jedes Skript anpassen.

PS: Da habe ich 'nohup' tatsächlich auch noch unterschlagen … auf die Verwendung von 'nohup' durch AVM selbst (beim set_modulemem) habe ich schon mal hingewiesen.

Zuletzt geändert vor 3 Jahren von PeterPawn (vorher) (Diff)

comment:32 als Antwort auf: ↑ 31 Geändert vor 3 Jahren durch er13

Replying to PeterPawn:

Aber es erhöht nach meiner Meinung die Konfusion, wenn sich ein Skript beim Start aus der rc.custom anders verhält, als wenn es aus einer anderen Umgebung (egal ob aus der debug.cfg bei AVM oder einer Telnet-Session) gestartet wird.

Das ist ja gerade das Problem - aus der Telnet-/SSH-Session bzw. dem Web-If gestartet beendet sich der Callmonitor bzw. ein Script NICHT, da er/es gar kein HUP erhält.

So wie es momentan verstehe, passiert folgendes. rc.S wird mit CTTY gestartet. Beim Beenden von rc.S wird CTTY geschlossen, woraufhin alle Kinder mit demselben CTTY ein SIGHUP erhalten. Warum es bei einer interaktiven Session (i.e. telnet, ssh) NICHT passiert, kann ich momemntan nicht erklären. Meiner Erwartung nach müsste es auch mit einem pseudo/virtual TTY (i.e. /dev/pts*) passieren - passiert aber nicht.

comment:33 Antwort: Geändert vor 3 Jahren durch er13

  • Lösung auf fixed gesetzt
  • Status von new nach closed geändert
  • Verantwortlicher auf er13 gesetzt

In 12978:

fwmod:

  • add code expected to be a fix for #2665
  • refs #2665

comment:34 Geändert vor 3 Jahren durch er13

  • Lösung fixed gelöscht
  • Status von closed nach reopened geändert

comment:35 als Antwort auf: ↑ 33 Geändert vor 3 Jahren durch er13

So, liebe Freunde, ich glaube ich hab's. Bitte testen und berichten. r12978 ist kein finaler Fix, es ist nur um zu testen, dass es a) das Problem behebt, b) sonst nichts im Spiel ist. Danke!

Sofern es funktioniert, so glaube ich, betrifft das Problem ausschließlich die Boxen mit FREETZ_AVM_HAS_UPDATE_FILESYSTEM_IMAGE, i.e 7390.06.2x wäre nicht betroffen.

Edit: und die Erklärung - bei Boxen mit filesystem_core greift die /etc/inittab aus filesystem_core und nicht aus filesystem.

Edit2: und mir ist sonst was aufgefallen - wir müssen uClibc und busybox in filesystem_core replacen.

Zuletzt geändert vor 3 Jahren von er13 (vorher) (Diff)

comment:36 Geändert vor 3 Jahren durch er13

In 12986:

  • replace /etc/inittab also in filesystem_core, this is a replacement for the test-code from r12978
  • refs #2665

comment:37 Geändert vor 3 Jahren durch er13

@KingTutt: könntest Du bitte meine Annahme bestätigen bzw. widerlegen, dass r12978 bzw. r12986 auch das von Dir gemeldete Problem beheben. Mein TestCase war der Callmonitor. Ich meine, bei Deinem und bei dem Callmonitor-Problem handelt es sich um das selbe Problem - verifiziert habe ich es jedoch nicht. Danke!

comment:38 Geändert vor 3 Jahren durch KingTutt

@er13: War keine gute Idee! Ich habe die FW (freetz-devel-12986) per Remote aufgespielt, was noch problemlos funktioniert hat.
Im Anschluss habe ich die rc.custom angepasst so dass mein Script wieder mit '&' gestartete wird. Leider musste ich beim anschließenden reboot feststellen, dass einfach nix passiert. Weder über die Freetz GUI noch über das AVM WebIF noch per Telnet wurde das reboot ausgeführt. Nach weiteren 5min. war die Box dann unerreichbar und bisher hat sie sich net wieder gemeldet. Muss also warten, bis jemand vorbei fährt zum Resetten. Danach ist mir das testen dieser Art per Remote zu heiß…

Edit: nach einem manuellen Coldplug scheint alles wieder zu funktionieren. Keine Ahnung was da schief gelaufen ist. Habe also mein script wieder mit '&' statt mit exec aus der rc.custom gestartet und das funktioniert wieder wie im Beispiel oben beschrieben. Auch ein anschließender Reboot funktionierte wieder ohne Probleme.

Ich habe zum Vergleich auch noch einmal ticket:2665#comment:7 folgend mit der FW 113.06.24-freetz-devel-12986 einen Aufruf mit strace gemacht, das hänge ich oben noch an.

Zuletzt geändert vor 3 Jahren von KingTutt (vorher) (Diff)

Geändert vor 3 Jahren durch KingTutt

Erstellt mit FW 113.06.24-freetz-devel-12987

comment:39 Geändert vor 3 Jahren durch er13

@KingTutt: Danke! Warum die Box sich aufgehängt hat, kann ich leider nicht sagen. Wir freuen uns zwar immer über eine schnelle Rückmeldung, wenn Du aber dafür irgendwelche Risiken eingehen musst bzw. es Dir Umstände bereitet (die Box nicht erreichbar, jemand muss vorbei fahren), dann ist es auch ok, wenn wir warten.

comment:40 Geändert vor 3 Jahren durch er13

  • Firmware Version von 113.06.23 nach all boxes/firmwares with wrapper filesystem geändert
  • Komponente von unknown nach patches geändert
  • Lösung auf fixed gesetzt
  • Product Id 7490 gelöscht
  • Status von reopened nach closed geändert
Hinweis: Hilfe zur Verwendung von Tickets finden Sie in TracTickets.