[Gelöst] "onlinechanged" wird manchmal nicht ausgeführt

RalfFriedl · 1 Sep 2011

Vermutlich wird die aufrufende Shell beendet, sonst wäre Dir aufgefallen, dass es noch den Prozess 10093 geben müsste.

Kannst Du mal am Anfang von /bin/onlinechanged.sh folgendes einbauen:

Code:

exec > /tmp/onlinechanged.$$.txt 2>&1
set -x

Vielleicht bringt das weitere Informationen. Interessant wäre vor allem das Protokoll vom offline Event, wenn das Skript nicht beendet wird. Es könnte sinnvoll sein, statt /tmp ein dauerhaftes Verzeichnis mit mehr Platz zu wählen. Wenn das online Event wartet, könnten im Laufe einiger Stunden einige MB zusammen kommen, was zu einem Reboot der Box führen könnte.

SaschaBr · 1 Sep 2011

Dann wurde die Shell beendet. Denn den Prozess mit 10093 gab es nicht (habe ps als txt.Datei vor dem Löschen von /var/run/onlinechanged gesichert).

Ich könnte das "exec >" auf meinem USB-Stick schreiben lassen. Mit welchen Datenmengen (und vor allem in welcher Zeit) muss ich denn rechnen? Ist ein USB-Stick schnell genug dafür?
Und wo und wie muss ich das "einbauen"?

EDIT:
So, um das auf meinen USB-Stick schreiben zu lassen, habe ich einen Ordner auf meinem USB-Stick für diese Mitschnitte angelegt, und den Code angepasst. Sollte so passen, oder?

Code:

exec > /var/media/ftp/LOGS/Onlinechanged/onlinechanged.$$.txt 2>&1
set -x

Nur wohin ich das jetzt einbauen muss, damit das nacher auf der Box landet, weiß ich nicht. :gruebel: (Hüüüülfe) :-D

RalfFriedl · 1 Sep 2011

Für eine dauerhafte Änderung im Buidl-System:

Code:

--- make/mod/files/root/bin/onlinechanged.sh    (Revision 7540)
+++ make/mod/files/root/bin/onlinechanged.sh    (Arbeitskopie)
@@ -1,4 +1,6 @@
 #!/bin/sh
+exec > /var/media/ftp/LOGS/Onlinechanged/onlinechanged.$$.txt 2>&1
+set -x
 PID_FILE=/var/run/onlinechanged
 OC_STATE="$@"

@@ -30,7 +32,7 @@
                # no startup/shutdown: wait for other onlinechanged to finish
                log "waiting"
                while [ -e $PID_FILE ]; do
-                       sleep 1
+                       sleep 60
                done
        fi
 fi

Ansonsten das Gleiche auf der Box mit mount --bind

Von den Datenmengen her ist es normalerweise relativ wenig, außer, wenn der zu beobachtende Fall eintritt, dass das online Event hängt. Dann kommen jede Sekunde zwei Zeilen dazu, ca. 50 Byte pro Sekunde oder 4MB pro Stunde. Man könnte das auch verhindern, in dem man nur beim offline Event die Protokollierung aktiviert.

Wenn das Problem auch auftritt, wenn man von Hand die Internet Verbindung trennt, kann man die Protokollierung im RAM lassen, weil die Box dann danach nicht stundenlang weiter läuft. Eine andere Möglichkeit ist, das sleep Intervall zu verlängern, wie im obigen Patch schon enthalten. Das ist zwar nicht schön, aber auch nicht weiter tragisch, das online Event verzögert sich dann eben etwas. Wenn das Problem behoben ist, kann man den Wert wieder zurück setzen.

SaschaBr · 1 Sep 2011

Ok, Firmware (r7555) mit der Änderung in onlinechanged.sh wird grade gebaut. Das sleep habe ich aber ganz bewusst nicht auf 60 geändert, da ich auf dem Stick (bei 4MB/ Std.) gut acht Tage loggen könnte, und ich denke, dass wir hier nicht zuviel auf einmal ändern sollten.

Werde die Firmware nachher flashen, und weiter Berrichten, sobald sich etwas ergibt.

EDIT:
Nur zur Info: Ich habe die Änderung anscheinend korrekt durchgeführt (danke Ralf), denn es wurde schon das erst Log (beim Starten der Box) auf dem USB-Stick abgelegt.

Stay tuned ...

olistudent · 2 Sep 2011

Der ctlmgr killt das onlinechanged-Event offline, wenn es noch läuft und die Box schon wieder online ist. Deshalb haben wir (bzw. cuma) den Start im Hintergrund eingebaut, da damit der Prozess eigentlich nicht mehr gekillt wird. Vielleicht ist hier noch ein Problem...

Gruß
Oliver

SaschaBr · 2 Sep 2011

Schon möglich, dass der ctlmgr dazwischen funkt. Bei mir stirbt das ~~aber~~ auch schon im ~~online~~ offline (oder tw. schon davor!?).
Auffällig ist auch der Zeitpunkt wann gekillt wird: Anfangs war es auffällig oft während vsftpd, heute beim eingebastelten onlineevent (welches jetzt vor vsftpd abgearbeitet wird). Oder eben anscheinend sogar so früh, das noch nicht einmal was im Log auftaucht (oder der Start wird komplett unterdrückt).
Scheinbar wird da immer noch was gekillt.

P.S.: Diese Nacht gab es keine Auffälligkeiten.

EDIT:
Korrektur: Bei mir wird das auch schon im offline gekillt ... war wohl heute morgen noch etwas früh ...

RalfFriedl · 2 Sep 2011

olistudent schrieb:
Der ctlmgr killt das onlinechanged-Event offline, wenn es noch läuft und die Box schon wieder online ist.

Weißt Du auch genau, wie er das Event killt, oder nur, dass es passiert? Hast Du einen strace vom ctlmgr, oder weißt Du nur, dass onlinechanged gekillt wird?

Kann man dieses Ereignis provozieren, ohne auf eine Zwangstrennung in der Nacht zu warten?

@SaschaBr
Wenn das Programm vorher gekillt wird, seit es mehr Ausgaben erzeugt, spricht das dafür, dass es nach einer bestimmten Zeit gekillt wird, unabhängig davon, was es gerade tut. Und wenn es zusätzlich Log-Ausgaben erstellt, ist es eben langsamer in der Abarbeitung dessen, was es hauptsächlich tun soll.

SaschaBr · 4 Sep 2011

Diese Nacht wurde Onlinechanged mal wieder abgewürgt! Hier die Logs und Mitschnitte:
onlinechanged.3426.txt (onlinechanged offline):

Code:

+ PID_FILE=/var/run/onlinechanged
+ OC_STATE=offline
+ [ -e /var/run/shutdown ]
+ [ -e /var/run/onlinechanged ]
+ touch /var/run/onlinechanged
+ [ ! -e /tmp/.modstarted ]
+ eventadd 1 Running onlinechanged: offline
+ log approved
+ local addline=
+ [ approved == -e ]
+ echo -e [3426]: [offline] approved
+ echo ONLINECHANGED[3426]: [offline] approved
+ logger -t ONLINECHANGED[3426] [offline] approved
+ [ ! -s /etc/onlinechanged/00-get_ip ]
+ log executing /etc/onlinechanged/00-get_ip
+ local addline=
+ [ executing /etc/onlinechanged/00-get_ip == -e ]
+ echo -e [3426]: [offline] executing /etc/onlinechanged/00-get_ip
+ echo ONLINECHANGED[3426]: [offline] executing /etc/onlinechanged/00-get_ip
+ logger -t ONLINECHANGED[3426] [offline] executing /etc/onlinechanged/00-get_ip
+ read line
+ sh /etc/onlinechanged/00-get_ip offline
+ [ ! -s /etc/onlinechanged/20-opendd ]
+ log executing /etc/onlinechanged/20-opendd
+ local addline=
+ [ executing /etc/onlinechanged/20-opendd == -e ]
+ echo -e [3426]: [offline] executing /etc/onlinechanged/20-opendd
+ echo ONLINECHANGED[3426]: [offline] executing /etc/onlinechanged/20-opendd
+ logger -t ONLINECHANGED[3426] [offline] executing /etc/onlinechanged/20-opendd
+ sh /etc/onlinechanged/20-opendd offline
+ read line
+ [ ! -s /etc/onlinechanged/chrony ]
+ log executing /etc/onlinechanged/chrony
+ local addline=
+ [ executing /etc/onlinechanged/chrony == -e ]
+ echo -e [3426]: [offline] executing /etc/onlinechanged/chrony
+ echo ONLINECHANGED[3426]: [offline] executing /etc/onlinechanged/chrony
+ logger -t ONLINECHANGED[3426] [offline] executing /etc/onlinechanged/chrony
+ sh /etc/onlinechanged/chrony offline
+ read line

onlinechanged.3443.txt (onlinechanged online)

Code:

+ PID_FILE=/var/run/onlinechanged
+ OC_STATE=online
+ [ -e /var/run/shutdown ]
+ [ -e /var/run/onlinechanged ]
+ [ ! -e /tmp/.modstarted ]
+ log waiting
+ local addline=
+ [ waiting == -e ]
+ echo -e [3443]: [online] waiting
+ echo ONLINECHANGED[3443]: [online] waiting
+ logger -t ONLINECHANGED[3443] [online] waiting
+ [ -e /var/run/onlinechanged ]
+ sleep 1
+ [ -e /var/run/onlinechanged ]
+ sleep 1
+ [ -e /var/run/onlinechanged ]
+ sleep 1
+ [ -e /var/run/onlinechanged ]
+ sleep 1
...

Syslog:

Code:

...
Sep  4 01:10:32 fritz user.notice ONLINECHANGED[3426]: [offline] approved
Sep  4 01:10:32 fritz user.notice ONLINECHANGED[3426]: [offline] executing /etc/onlinechanged/00-get_ip
Sep  4 01:10:32 fritz user.notice ONLINECHANGED[3426]: [offline] executing /etc/onlinechanged/20-opendd
Sep  4 01:10:32 fritz user.notice ONLINECHANGED[3426]: [offline] executing /etc/onlinechanged/chrony
Sep  4 01:10:32 fritz user.notice ONLINECHANGED[3443]: [online] waiting
...

P.S.: Und nach dem Löschen von /var/run/onlinachanged via Konsole lief onlinechanged online dann ganz normal an und durch.

RalfFriedl · 4 Sep 2011

Interessant ist hauptsächlich der erste Teil. Dass das online Event wartet, hatten wir auch vorher schon herausgefunden. Leider steht nichts davon, warum das Skript beendet wird.
Kannst Du strace auf alle ctlmgr Prozesse laufen lassen, um herauszufinden, wie das Skript gekillt wird?

Edit:
Kannst Du in das Skript noch folgendes am Anfang einbauen:

Code:

for i in 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20; do
  trap "echo trap $i" $i
done

Am Besten erst mal in einem anderen Skript testen. Mit etwas Glück finden wir so heraus, welches Signal kommt.

SaschaBr · 4 Sep 2011

Hmm... mit strace weiß ich nicht mit um... Da bräuchte ich dann etwas Unterstüzung.

Diese beiden Codezeilen sollen also auch in die onlinechanged.sh? Vor oder nach den beiden Zeilen die ich mit Deiner Hilfe dort eingefügt habe?

RalfFriedl · 4 Sep 2011

Ändere das mal besser auf

Code:

for i in 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 ; do
  trap "echo trap $i" $i
done

Ob vor oder nach den beiden anderen Zeilen spielt keine Rolle. Der Effekt ist, dass am Ende des Skripts trap und eine Zahl ausgegeben wird, sofern nicht mit SIGKILL gekillt wird. In diesem Fall würde die Shell sofort beendet, ohne dass sie noch irgend etwas ausgeben kann. Dabei bedeutet "trap 0", dass die Shell regulär beendet wurde, eine andere zahl bedeutet, dass das entsprechende Signal empfangen wurde. Ein Signal 18 kommt anscheinend nach jeder Anweisung, daher ist hier die Liste kürzer, die Signal bis 15 sollten reichen.

SaschaBr · 5 Sep 2011

OK, habe ich eingebaut und grade geflasht. Beim Starten der Box hatte ich dann am Ende des Mitschnitts

Code:

+ echo trap 0
trap 0

stehen.
Jetzt heißt es also wieder: warten!

Stay tuned...

RalfFriedl · 5 Sep 2011

Das "trap 0" bedeutet, die Shell ist regulär beendet. Ich vermute, dass dabei auch alles bis zum Ende abgearbeitet wurde.

SaschaBr · 5 Sep 2011

Ja, ist (beim Starten der Box vorhin) ganz normal bis zum Ende durchgelaufen.

kriegaex · 17 Sep 2011

kriegaex schrieb:
Was soll ich wo einbauen als Log-Ausgabe, welchen Prozeß soll ich zwischen 4 und 5 Uhr morgens stracen (Achtung, ich habe keinen replaced Kernel, also kann ich evtl. Forks nicht tracen)?

Darauf habe ich noch keine Antwort erhalten oder sie überlesen. Ich würde gern helfen.

kriegaex schrieb:
So, ich habe mal zusätzliche Log-Ausgaben an den Beginn der beiden Onlinechanged-Skripten in /bin eingetragen:

Code:

echo "$(date) - $# / $@ - /bin/onlinechanged" >> /var/media/ftp/Generic-FlashDisk-03/new_ip.log

Außerdem habe ich unter /etc/onlinechanged/00-aaa ein Skript eingebaut, welches eine ähnliche Zeile als einzige Aktion enthält.

Ich weiß nicht, ob das noch jemanden interessiert oder jemandem hilft, aber ich habe mal einige Tage mitgeloggt. Unten folgt ist das Ergebnis. Wie man sieht, wird an manchen Tagen alles normal ausgeführt, dann wieder an anderen kein einziges Skript:

Code:

Sun Aug 28 04:13:25 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Sun Aug 28 04:13:25 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Sun Aug 28 04:13:25 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Sun Aug 28 04:13:26 CEST 2011  -  1 / online  -  /bin/onlinechanged
Sun Aug 28 04:13:26 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Sun Aug 28 04:13:28 CEST 2011  -  1 / offline
Sun Aug 28 04:13:29 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Sun Aug 28 04:13:33 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Mon Aug 29 04:12:08 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Mon Aug 29 04:12:08 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Mon Aug 29 04:12:08 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Mon Aug 29 04:12:09 CEST 2011  -  1 / online  -  /bin/onlinechanged
Mon Aug 29 04:12:09 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Mon Aug 29 04:12:11 CEST 2011  -  1 / offline
Mon Aug 29 04:12:12 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Mon Aug 29 04:12:16 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Thu Sep  1 04:08:39 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Thu Sep  1 04:08:39 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Thu Sep  1 04:08:39 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Thu Sep  1 04:08:40 CEST 2011  -  1 / online  -  /bin/onlinechanged
Thu Sep  1 04:08:40 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Thu Sep  1 04:08:43 CEST 2011  -  1 / offline
Thu Sep  1 04:08:43 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Thu Sep  1 04:08:48 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Fri Sep  2 04:07:37 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Fri Sep  2 04:07:37 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Fri Sep  2 04:07:37 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Fri Sep  2 04:07:38 CEST 2011  -  1 / online  -  /bin/onlinechanged
Fri Sep  2 04:07:38 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Fri Sep  2 04:07:41 CEST 2011  -  1 / offline
Fri Sep  2 04:07:41 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Fri Sep  2 04:07:45 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Fri Sep  2 17:56:58 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Fri Sep  2 17:56:58 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Fri Sep  2 17:56:58 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Fri Sep  2 17:57:03 CEST 2011  -  1 / offline
Fri Sep  2 17:57:03 CEST 2011  -  1 / online  -  /bin/onlinechanged
Fri Sep  2 17:57:03 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Fri Sep  2 17:57:03 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Fri Sep  2 17:57:08 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Fri Sep  2 17:57:41 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Fri Sep  2 17:57:41 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Fri Sep  2 17:57:41 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Fri Sep  2 17:57:46 CEST 2011  -  1 / online  -  /bin/onlinechanged
Fri Sep  2 17:57:46 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Fri Sep  2 17:57:46 CEST 2011  -  1 / offline
Fri Sep  2 17:57:47 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Fri Sep  2 17:57:51 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Fri Sep  2 18:02:21 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Fri Sep  2 18:02:21 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Fri Sep  2 18:02:21 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Fri Sep  2 18:02:25 CEST 2011  -  1 / offline
Fri Sep  2 18:02:26 CEST 2011  -  1 / online  -  /bin/onlinechanged
Fri Sep  2 18:02:26 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Fri Sep  2 18:02:26 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Fri Sep  2 18:02:31 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Fri Sep  2 20:24:52 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Fri Sep  2 20:24:52 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Fri Sep  2 20:24:52 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Fri Sep  2 20:24:57 CEST 2011  -  1 / offline
Fri Sep  2 20:24:57 CEST 2011  -  1 / online  -  /bin/onlinechanged
Fri Sep  2 20:24:57 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Fri Sep  2 20:24:57 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Fri Sep  2 20:25:02 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Fri Sep  2 20:25:11 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Fri Sep  2 20:25:11 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Fri Sep  2 20:25:11 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Fri Sep  2 20:25:15 CEST 2011  -  1 / offline
Fri Sep  2 20:25:16 CEST 2011  -  1 / online  -  /bin/onlinechanged
Fri Sep  2 20:25:16 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Fri Sep  2 20:25:17 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Fri Sep  2 20:25:21 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Sat Sep  3 04:06:33 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Sat Sep  3 04:06:33 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Sat Sep  3 04:06:33 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Sat Sep  3 04:06:34 CEST 2011  -  1 / online  -  /bin/onlinechanged
Sat Sep  3 04:06:34 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Sat Sep  3 04:06:36 CEST 2011  -  1 / offline
Sat Sep  3 04:06:37 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Sat Sep  3 04:06:42 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Wed Sep  7 04:01:57 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Wed Sep  7 04:01:57 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Wed Sep  7 04:01:57 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Wed Sep  7 04:01:58 CEST 2011  -  1 / online  -  /bin/onlinechanged
Wed Sep  7 04:01:58 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Wed Sep  7 04:02:01 CEST 2011  -  1 / offline
Wed Sep  7 04:02:01 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Wed Sep  7 04:02:06 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Wed Sep  7 04:59:16 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Wed Sep  7 04:59:16 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Wed Sep  7 04:59:16 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Wed Sep  7 04:59:17 CEST 2011  -  1 / online  -  /bin/onlinechanged
Wed Sep  7 04:59:17 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Wed Sep  7 04:59:20 CEST 2011  -  1 / offline
Wed Sep  7 04:59:20 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Wed Sep  7 04:59:25 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Thu Sep  8 04:58:21 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Thu Sep  8 04:58:21 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Thu Sep  8 04:58:21 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Thu Sep  8 04:58:22 CEST 2011  -  1 / online  -  /bin/onlinechanged
Thu Sep  8 04:58:22 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Thu Sep  8 04:58:25 CEST 2011  -  1 / offline
Thu Sep  8 04:58:25 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Thu Sep  8 04:58:30 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Fri Sep  9 04:57:01 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Fri Sep  9 04:57:01 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Fri Sep  9 04:57:01 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Fri Sep  9 04:57:02 CEST 2011  -  1 / online  -  /bin/onlinechanged
Fri Sep  9 04:57:02 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Fri Sep  9 04:57:05 CEST 2011  -  1 / offline
Fri Sep  9 04:57:05 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Fri Sep  9 04:57:10 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Sat Sep 10 04:55:51 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Sat Sep 10 04:55:51 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Sat Sep 10 04:55:51 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Sat Sep 10 04:55:52 CEST 2011  -  1 / online  -  /bin/onlinechanged
Sat Sep 10 04:55:52 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Sat Sep 10 04:55:55 CEST 2011  -  1 / offline
Sat Sep 10 04:55:55 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Sat Sep 10 04:56:01 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Sun Sep 11 04:54:31 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Sun Sep 11 04:54:31 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Sun Sep 11 04:54:32 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Sun Sep 11 04:54:32 CEST 2011  -  1 / online  -  /bin/onlinechanged
Sun Sep 11 04:54:32 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Sun Sep 11 04:54:35 CEST 2011  -  1 / offline
Sun Sep 11 04:54:35 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Sun Sep 11 04:54:40 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Fri Sep 16 04:48:49 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Fri Sep 16 04:48:49 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Fri Sep 16 04:48:49 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Fri Sep 16 04:48:50 CEST 2011  -  1 / online  -  /bin/onlinechanged
Fri Sep 16 04:48:50 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Fri Sep 16 04:48:53 CEST 2011  -  1 / offline
Fri Sep 16 04:48:54 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Fri Sep 16 04:48:58 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)
Sat Sep 17 04:47:27 CEST 2011  -  1 / offline  -  /bin/onlinechanged
Sat Sep 17 04:47:27 CEST 2011  -  1 / offline  -  /bin/onlinechanged.sh
Sat Sep 17 04:47:27 CEST 2011  -  1 / offline  -  /etc/onlinechanged/00-aaa
Sat Sep 17 04:47:28 CEST 2011  -  1 / online  -  /bin/onlinechanged
Sat Sep 17 04:47:28 CEST 2011  -  1 / online  -  /bin/onlinechanged.sh
Sat Sep 17 04:47:31 CEST 2011  -  1 / offline
Sat Sep 17 04:47:31 CEST 2011  -  1 / online  -  /etc/onlinechanged/00-aaa
Sat Sep 17 04:47:36 CEST 2011  -  1 / online
aaa.bbb.ccc.ddd (meine IP an diesem Tag)

Insgesamt ist an 9 von 21 Tagen keine Log-Ausgabe zu verzeichnen.

RalfFriedl · 17 Sep 2011

Du könntest die Änderung einbauen, die ich SaschaBr in [POST=1749774]#83[/POST] empfohlen hatte. Falls das Skript nicht sofort mit KILL beendet wird, würde man dann sehen, welches Signal zum Beenden kommt.
Ansonsten ist ctlmgr im Verdacht, das Signal zu senden. Du könntest also strace auf alle ctlmgr Prozesse laufen lassen, in der Hoffnung, dass das Signal von einem dieser Prozesse kommt und der nicht vorher forkt. Beim strace sollte die Option -tt für die Angaben der Zeit enthalten. Außerdem ist es vielleicht übersichtlicher, für jeden Prozess ein eigens strace in eine eigene Datei laufen zu lassen, die natürlich auf einem externen Speicher liegen sollte.

SaschaBr · 17 Sep 2011

Es ist ja schon kurios: Seitdem ich die von RalfFriedl vorgeschlagene Änderung an onlinechanged.sh durchgeführt habe, um dem Fehler auf die Schliche zu kommen, habe ich kein abgewürgtes onlinechanged mehr beobachten können.
Nun denn, da ich aber auch andere Probleme mit der 05.05er habe (z.B. die nicht funktionierenden Siemens Cx - Telefone), habe ich mir gestern mit der aktuellen Labor-Firmware (54.05.07-20651) via Firmware-Override im Trunk eine Firmware bauen lassen und geflasht. Mal sehen, eventuell hat AVM ja auch diesen Fehler des "Abwürgens" beseitigen können. Ich werde auf jedenfall berrichten.

olistudent · 17 Sep 2011

Kann es sein, dass du das echo nicht mitbekommst? Vielleicht mal durch logger ersetzen und in den Syslog schreiben lassen?

Gruß
Oliver

RalfFriedl · 17 Sep 2011

Da das echo ausgeführt wird, nachdem die Ausgabe in eine Datei gelenkt wird, sollte man das auch mitbekommen, wobei eine Ausgabe ins syslog auch nicht schadet.

Wenn aber derzeit das Problem nicht mehr auftritt, gibt es nicht viel zu beobachten.

kriegaex · 17 Sep 2011

RalfFriedl schrieb:
Du könntest die Änderung einbauen, die ich SaschaBr in [POST=1749774]#83[/POST] empfohlen hatte.

In meinen Skripts (/bin/onlinechanged, /bin/onlinechanged.sh, /etc/onlinechanged/00-aaa, /tmp/onlinechanged/new_ip_email) steht nun jeweils am Anfang:

Code:

for i in 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 ; do
    trap "echo \"$(date -Iseconds)  -  $0  -  trap $i\" >> /var/media/ftp/Generic-FlashDisk-03/new_ip.log" $i
done
echo "$(date -Iseconds)  -  $0  -  $@" >> /var/media/ftp/Generic-FlashDisk-03/new_ip.log

Das sieht im Log dann so aus, wenn ich manuell onlinechanged online aufrufe:

Code:

2011-09-17T13:27:04+0200  -  /bin/onlinechanged  -  online
2011-09-17T13:27:04+0200  -  /bin/onlinechanged  -  trap 0
2011-09-17T13:27:04+0200  -  /bin/onlinechanged.sh  -  online
2011-09-17T13:27:04+0200  -  /etc/onlinechanged/00-aaa  -  online
2011-09-17T13:27:04+0200  -  /etc/onlinechanged/00-aaa  -  trap 0
2011-09-17T13:27:05+0200  -  /tmp/onlinechanged/new_ip_email  -  online
2011-09-17T13:27:05+0200  -  /tmp/onlinechanged/new_ip_email  -  trap 0
2011-09-17T13:27:04+0200  -  /bin/onlinechanged.sh  -  trap 0

Ob und wie ich strace automatisch starte in der Nacht, so daß es alle ctlmgr-Prozesse erfaßt zwischen vier und fünf Uhr und nicht 24 Stunden mitloggt, überlege ich mir noch. Nicht, daß mir der USB-Stick voll läuft.

[Gelöst] "onlinechanged" wird manchmal nicht ausgeführt

IPPF-Urgestein

Aktives Mitglied

IPPF-Urgestein

Aktives Mitglied

IPPF-Urgestein

Aktives Mitglied

IPPF-Urgestein

Aktives Mitglied

IPPF-Urgestein

Aktives Mitglied

IPPF-Urgestein

Aktives Mitglied

IPPF-Urgestein

Aktives Mitglied

Aktives Mitglied

IPPF-Urgestein

Aktives Mitglied

IPPF-Urgestein

IPPF-Urgestein

Aktives Mitglied

Statistik des Forums