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

Sidebar Sidebar
Upgrade 3CX to v18 and get it hosted free!
SaschaBr schrieb:
Zumindest dem AVM-Log nach hat die Box aber eine IP-Adresse bekommen. Sollte also eigentlich passen ...
Zum Vergrößern anklicken....
Anscheinend reicht eine neue (andere) IP-Adresse die die Box bekommen hat, nicht aus, um das onlinechanged-Ereignis auszulösen. Ich denke es muss auch Internetverbindung vorhanden sein (evtl. prüft die Box das), um das onlinechanged-Ereignis auszulösen. Z. B. bekommt meine Box nach einem reboot (Neustart) eine neue IP-Adresse (192.168.100.2), hat aber verständlicherweise mit dieser IP-Adresse kein Internetanschluss(/zugang), so dass nicht einmal versucht wird, das onlinechanged-Ereignis auszulösen:
Code: 
20.03.11	14:01:12	Internetverbindung wurde erfolgreich hergestellt. IP-Adresse: ##.#.2##.##, DNS-Server: 82.###.##.## und 78.##.##.##, Gateway: ##.#.2##.#
20.03.11	14:01:09	Internetverbindung wurde getrennt.
20.03.11	14:00:52	Internetverbindung wurde erfolgreich hergestellt. IP-Adresse: [COLOR="red"]192.168.100.2[/COLOR], DNS-Server: 0.0.0.0 und 0.0.0.0, Gateway: 0.0.0.0
20.03.11	14:00:52	Internetverbindung wurde getrennt.
20.03.11	14:00:42	Internetverbindung wurde erfolgreich hergestellt. IP-Adresse: [COLOR="red"]192.168.100.2[/COLOR], DNS-Server: 0.0.0.0 und 0.0.0.0, Gateway: 0.0.0.0
Oder erkennt die Box, dass es sich hier um eine private IP-Adresse handelt, und löst deshalb das onlinechanged-Ereignis nicht aus?
 
Onlinechanged soll ja bei der Zwangstrennung nach dem wieder Online sein aufgerufen werden. Dabei ist es aber völlig egal, ob sich die externe IP-Adresse ändert, oder (selten) auch mal bleibt: Es wird auch dann onlinechanged aufgerufen.

Und eine interne IP habe ich bei meiner Box dort noch nie im AVM-Log gesehen.

Ich habe ehr den Verdacht, dass diese vorgezogene Zwangstrennung zu schnell geht, und onlinechanged das nicht mit bekommt.
 
Ich hatte damit meinen Anschluss gemeint.
 
Wollte damit sagen dass onlinechanged auch ausgeführt wird wenn bei "Internetverbindung wurde erfolgreich hergestellt." die IP sich nicht verändert. Diese Meldung erscheint seit ein paar FW-Versionen täglich
 
SaschaBr schrieb:
Onlinechanged soll ja bei der Zwangstrennung nach dem wieder Online sein aufgerufen werden. Dabei ist es aber völlig egal, ob sich die externe IP-Adresse ändert, oder (selten) auch mal bleibt: Es wird auch dann onlinechanged aufgerufen.
...
Zum Vergrößern anklicken....
Ja, Du hast recht. onlinechanged wird immer nach einem Neustart der Box, nach der Zwangstrennung und auch "nur" nach einer Änderung der IP-Adresse, aufgerufen. Und das, unabhängig ob die Box nach dem Neustart/Zwangstrennung, überhaupt eine IP-Adresse bekommen hat, nur eine private IP-Adresse bekommen hat, eine öffentliche (externe) IP-Adresse bekommen hat und/oder eine Internetverbindung (z. Zeitpunkt des onleinchanged-Ereignisses) hat. Ich habe das mal mit einem Skript getestet:
Code: 
PATH1=/var/media/ftp/uStor01

start() {
        echo "$(date && /usr/bin/get_ip -d)" >> $PATH1/my_iparchiv
	logger -t info [ip_archiv] "$(date && /usr/bin/get_ip -d)"
        }
Und das ist das Ergebnis:
Code: 
Sun Mar 20 18:43:18 CET 2011
Sun Mar 20 18:43:20 CET 2011
192.168.100.2
Sun Mar 20 18:43:49 CET 2011
##.#.2##.##
D. h. sofort nach dem reboot hat die Box keine IP-Adresse, dann wird vom Skript nur Datum und Uhrzeit gespeichert. 2 Sekunden später hat die Box eine private IP-Adresse (hier 192.168.100.2), die vom Skript auch gespeichert wird. 29 Sekunden später, d. h. nach dem Neustart des Kabelmodems, hat die Box die "lang ersehnte" öffentliche IP-Adresse, die dann vom Skript auch gespeichert wird. (Skript = onlinechanged-Ereignis). D. h., ich habe 3 Einträge, obwohl die Box nur einmal neu gestartet ist.
 
Habe mir am Wochenende eine aktuelle Firmware (r6833) gebaut, bei der ja die Onlinechanged-Ereignisse nun auch mitgeloggt werden.
Nun, diese Nacht ist es wieder passiert: "onlinechanged online" wurde nicht ausgeführt. Glücklicherweise hat sich meine externe IP diesmal nicht geändert, wodurch ich weiterhin Zugriff von außen hatte.
Hier der Syslog aus dem entsprechendem Zeitraum:

Code: 
Apr 18 04:44:32 fritz user.notice ONLINECHANGED[13425]: [offline] approved
Apr 18 04:44:32 fritz user.notice ONLINECHANGED[13425]: [offline] executing /etc/onlinechanged/20-opendd
Apr 18 04:44:32 fritz user.notice ONLINECHANGED[13425]: [offline] executing /etc/onlinechanged/chrony
Apr 18 04:44:32 fritz daemon.info chronyd[3774]: Source 178.26.105.100 offline
Apr 18 04:44:32 fritz daemon.info chronyd[3774]: Source 188.165.211.42 offline
Apr 18 04:44:32 fritz user.notice ONLINECHANGED[13425]: [offline]  * 200 OK
Apr 18 04:44:32 fritz user.notice ONLINECHANGED[13425]: [offline]  * 200 OK
Apr 18 04:44:33 fritz user.notice ONLINECHANGED[13425]: [offline] executing /etc/onlinechanged/vsftpd
Apr 18 04:44:33 fritz user.notice ONLINECHANGED[13425]: [offline] executing /etc/onlinechanged/webdav_net
Apr 18 04:44:33 fritz user.notice ONLINECHANGED[13460]: [online] rejected
Apr 18 04:44:33 fritz user.notice ONLINECHANGED[13425]: [offline] done


Was mir das "[online] rejected" sagen soll ist mir nicht klar (was rejected heißt weiß ich wohl). Auch wieso das vor "[offline] done" im Log steht erscheint mir merkwürdig, passt aber auch zu dieser Beobachtung im AVM-Log (Achtung: von unten nach oben lesen, unwichtige Meldungen entfernt):
Dort steht nur "Running onlinechanged: offline", aber kein "online"?? Außerdem erscheint das "offline" erst nachdem die Verbindung schon wieder hergestellt wurde!?

Code: 
18.04.11	04:44:33	Running onlinechanged: offline
18.04.11	04:44:32	Internetverbindung wurde erfolgreich hergestellt. IP-Adresse: 77.9.xxx.xxx, DNS-Server: 193.189.250.99 und 193.189.244.205, Gateway: 213.20.58.3, Breitband-PoP: rdsl-wprt-de01
18.04.11	04:44:32	Internetverbindung wurde getrennt.
18.04.11	04:44:28	Die Internetverbindung wird kurz unterbrochen, um der Zwangstrennung durch den Anbieter zuvorzukommen.

Ist die Zwangstrennung bei mir tatsächlich zu schnell erledigt, sodass "onlinechanged" nicht mitkommt? Was könnte ich dagegen tun?
 
Code: 
# quit if another onlinechanged is yet running

@cuma
Das kommt vom &. ;-)

Gruß
Oliver
 
SaschaBr schrieb:
Was mir das "[online] rejected" sagen soll ist mir nicht klar
Zum Vergrößern anklicken....
Das "online" wird nicht ausgeführt da noch ein "offline". Geplant war nicht mehrere onlinechanged parallel laufen zu lassen. Aber wohl noch nicht die beste Lösung ...

olistudent schrieb:
@cuma
Das kommt vom &. ;-)
Zum Vergrößern anklicken....
Ist aber kein Fehler sondern so beabsichtigt :p

Problematisch ist das Timing, dass "online" so schnell nach "offline" kommt. Beim Systemstart funktioniert es so wie es ist gut, da dort je nach Paketauswahl 5 Events ausgelöst werden aber man nur 1x online braucht
Ich hätte da 2 Ideen, vielleicht hat noch jemand bessere:
* Die Dinge die onlinechanged aufruft mit & starten um schneller mit dem Hauptscript fertig zu sein (dann könnten Dinge parallel laufen)
* Wenn .modstartet da ist (also nach erfolgreichem Sytemstart) wartet "online" bis ein evtl laufendes "offline" fertig ist (außer Programmieraufwand seh ich keine Nachteile)
 
Eine weitere Idee:
Könnte man das nicht so drehen, das wenn ein "rejected" ausgeworfen/ ausgewertet wird, ein weiterer Versuch ein par Sekunden später ausgelöst wird?
 
Cool, danke.
Baue grade eine Firmware mit diesem Update von Dir. Ich werde auf alle Fälle hier Bericht erstatten.
 
Hier die versprochene Berichterstattung:

Meine Zwangstrennung diese Nacht war heute tatsächlich mal wieder schnell genug, um die Änderung aus r6870 testen zu können:
Code: 
...
Apr 26 04:15:52 fritz user.notice ONLINECHANGED[30485]: [offline]  * 200 OK
Apr 26 04:15:52 fritz user.notice ONLINECHANGED[30485]: [offline] executing /etc/onlinechanged/vsftpd
Apr 26 04:15:52 fritz user.notice ONLINECHANGED[30485]: [offline] executing /etc/onlinechanged/webdav_net
Apr 26 04:15:53 fritz user.notice ONLINECHANGED[30518]:[COLOR="red"] [online] waiting[/COLOR]
Apr 26 04:15:53 fritz user.notice ONLINECHANGED[30485]: [COLOR="red"][offline] done[/COLOR]
Apr 26 04:15:54 fritz user.notice ONLINECHANGED[30518]: [COLOR="red"][online] approved[/COLOR]
Apr 26 04:15:54 fritz user.notice ONLINECHANGED[30518]: [online] executing /etc/onlinechanged/20-opendd
Apr 26 04:15:54 fritz daemon.info opendd[30559]: -- running OpenDD 0.7.9 in normal mode
...

@cuma: Somit scheint Deine Änderung so zu funktionieren, wie Du es Dir ausgedacht hast.
Nochmals vielen Dank!

EDIT:

Und auch eine nicht zu schnelle Zwangstrennung diese Nacht hat sauber funktioniert:
Code: 
...
Apr 27 04:14:30 fritz user.notice ONLINECHANGED[10956]: [offline] executing /etc/onlinechanged/webdav_net
Apr 27 04:14:31 fritz user.notice ONLINECHANGED[10956]: [offline] done
Apr 27 04:14:31 fritz user.notice ONLINECHANGED[11009]: [online] approved
Apr 27 04:14:31 fritz user.notice ONLINECHANGED[11009]: [online] executing /etc/onlinechanged/20-opendd
...

Ich setze den Thread jetzt auf [gelöst].
 
Zuletzt bearbeitet:
So ein Sch***!
Diese Nacht wurde "Onlinechanged" trotz vorgezogener Zwangstrennung gar nicht aufgerufen, will heißen: In keinem Log ist auch nur ansatzweise was von Onlinechanged zu sehen!?
Nun ja, wie olistudent schon schrieb, wird das ja vom multid angestoßen. Vieleicht war es ja diesmal sogar dem multid zu schnell (trennen und neue IP in der gleichen Sekunde). Da wird wohl nur AVM was drann drehen können.
 
Hmmm... Auch wenn es so aussieht, dass ich hier Selbstgespräche führe, dem ist nicht so: Hier scheinen ein par Posts (z.B. von cuma) abhanden gekommen zu sein? Wann ist denn das passiert??

Zum Thema:
Das Problem, das "Onlinechanged" nicht ausgeführt wird besteht bei mir leider nach wie vor. Immer wieder wird bei extrem kurzen Zwangstrennungen dieses Script einfach nicht aufgerufen (zum Beispiel die letzten beiden Nächste).

Das weiteren hatte ich letztes Wochenende (ich war mit meiner Familie für ein par Tage in einem Kinder-Freizeitpark) ein weiteres mergwürdiges Problem, bei dem Onlinechanged selbst wohl der Fehler war:
Onlinechanged wurde zwar angestoßen, wurde aber auf "warte" gesetzt, da eine andere Instanz noch lief, und das über drei Tage hinweg. In der Konsole konnte man in ps sehen, dass "/bin/onlinechanged online" noch aktiv war. Auch ein Kill brachte nichts, und ich musste daher einen Reboot der Box auslösen (leider habe ich dazu keine Logs mehr).

Gibt es noch irgendeine Möglichkeit dieses Problem zu "debuggen"? Oder einfach die Zwangstrennung zu verlangsamen???
 
Es ist nicht zu fassen, habe nur ich das Problem? Irgendwas passt hier doch nicht!?
Das passiert jetzt nicht zum ersten mal (wie weiter oben ja auch schon mal geschildert).

Hier ein Log wenn Onlinechanged richtig funktioniert hat:
Code: 
[4438]: [offline] approved
[4438]: [offline] executing /etc/onlinechanged/00-get_ip
[4438]: [offline] executing /etc/onlinechanged/20-opendd
[4438]: [offline] executing /etc/onlinechanged/chrony
[4455]: [online] waiting
[4438]: [offline]  * 200 OK
[4438]: [offline]  * 200 OK
[4438]: [offline] executing /etc/onlinechanged/vsftpd
[4438]: [offline] done
[4455]: [online] approved
[4455]: [online] executing /etc/onlinechanged/00-get_ip
[4455]: [online] executing /etc/onlinechanged/20-opendd
[4455]: [online]  * Running OpenDD ... done.
[4455]: [online] executing /etc/onlinechanged/chrony
[4455]: [online]  * 200 OK
[4455]: [online]  * 200 OK
[4455]: [online]  * 513 RTC driver not running
[4455]: [online] executing /etc/onlinechanged/vsftpd
[4455]: [online]  * Reloading vsftpd ... inetd.
[4455]: [online] done

Und hier ein Log, bei dem Onlinechanged hängen geblieben ist:
Code: 
[20739]: [offline] approved
[20739]: [offline] executing /etc/onlinechanged/00-get_ip
[20739]: [offline] executing /etc/onlinechanged/20-opendd
[20739]: [offline] executing /etc/onlinechanged/chrony
[20739]: [offline]  * 200 OK
[20761]: [online] waiting

PS zu diesem Zeitpunkt:
Code: 
root@fritz:/var/mod/root# ps
  PID USER       VSZ STAT COMMAND
    1 root      1148 S    init
    2 root         0 SW   [kthreadd]
    3 root         0 SW   [ksoftirqd/0]
    4 root         0 SW   [events/0]
    5 root         0 SW   [khelper]
    6 root         0 SW   [async/mgr]
    7 root         0 SW   [CPMAC workqueue]
    8 root         0 SW   [sync_supers]
    9 root         0 SW   [bdi-default]
   10 root         0 SW   [kblockd/0]
   11 root         0 SW   [khubd]
   12 root         0 SW   [rpciod/0]
   13 root         0 SW   [kswapd0]
   14 root         0 SW   [aio/0]
   15 root         0 SW   [nfsiod]
   20 root         0 SW   [pm_info]
   21 root         0 SWN  [avmdebug]
   22 root         0 SW   [mtdblockd]
   23 root         0 SW   [tffsd_mtd_0]
   79 root         0 SW   [cleanup_timer_f]
  181 root         0 SWN  [jffs2_gcd_mtd5]
  188 root         0 SW   [capi_oslib]
  189 root         0 SW   [capi_oslib/0]
  190 root         0 SW   [capitransp]
  193 root         0 SW<  [avm_dect_thread]
  194 root         0 SW   [ksock tcp worke]
  195 root         0 SW   [ksock tcp serve]
  314 root         0 SW   [scsi_eh_0]
  317 root         0 SW   [usb-storage]
  333 root         0 SW   [scsi_eh_1]
  340 root         0 SW   [usb-storage]
  440 root      1064 S <  /sbin/udevd --daemon
  639 root      3888 S    /bin/configd
  959 root      1064 S <  /sbin/udevd --daemon
  981 root         0 SWN  [dectuart_route]
 1000 root     11232 S    /usr/bin/ctlmgr.bin
 1013 root      5472 S    upnpd
 1057 root      4408 S    multid -t
 1147 root     11232 S    /usr/bin/ctlmgr.bin
 1148 root     11232 S    /usr/bin/ctlmgr.bin
 1149 root     11232 S    /usr/bin/ctlmgr.bin
 1159 root         0 SW   [flush-8:0]
 1458 root      4408 S    multid -t
 1533 root      5472 S    upnpd
 1534 root      5472 S    upnpd
 1535 root      5472 S    upnpd
 1539 root      1168 S    dropbear -i -s -R
 1543 root      1156 S    -sh
 1663 root      1132 S    sleep 59
 1672 root      1132 S    sleep 60
 1722 root      3976 S    usermand
 1723 root      1132 S    sleep 59
 1727 root      4180 S    contfiltd
 1746 root      1136 S    sleep 1
 1747 root      1144 R    ps
 1887 root      1064 S <  /sbin/udevd --daemon
 1892 root      4528 S    dsld -i -n
 1900 root      5192 S    telefon a127.0.0.1
 1904 root      5048 S <  voipd
 1911 root      3748 S    pbd
 1912 root      3748 S    pbd
 1915 root      3748 S    pbd
 1916 root      3748 S    pbd
 1933 root      5192 S    telefon a127.0.0.1
 1934 root      5192 S    telefon a127.0.0.1
 1939 root      4572 S    dect_manager
 2017 root      3044 S    hostapd -B /var/tmp/wlan_ath0_topology
 2435 root       824 S    /bin/run_clock -c /dev/tffs -d
 2566 root      1160 S    crond -b
 2593 root      1140 S    httpd-webcfg -P /var/run/webcfg.pid -p 91 -c /mod/et
 2648 root      1136 S    syslogd -L -O /var/media/ftp/LOGS/Syslog/syslog.fbt
 2683 root      1140 S    inetd
 3193 root      2356 S    nmbd -D -s /mod/etc/samba/smb.conf
 3287 root         0 SWN  [kdsld_token]
 3399 root      1140 S    /bin/sh /usr/bin/spindown sdb 900 3
 3853 root      1148 S    init
 3885 root      1180 S    /sbin/chronyd -f /var/tmp/chrony.conf
 7944 root      1172 S    /bin/sh /etc/default.rrdstats/rrdstats 60
20761 root      1152 S    /bin/sh /bin/onlinechanged.sh online

Anghängt habe ich auch die Freetz-Support-Datei.
 
Das onlinechanged online wartet darauf, dass das offline Event abgearbeitet wird. Das läuft aber nicht durch. Wird das evtl. von AVM gekillt, wenn während dem offline schon wieder online kommt?

Gruß
Oliver
 
Gute Frage, aber durchaus möglich: Das passiert (wenn ich mich richtig erinnere) immer nur dann wenn das "online" vor der kompletten Abarbeitung von "offline" kommt (er also auf "waiting" steht). Ich werde das mal beobachten und berichten.
Wie kann ich denn das Event "offline" abschließen, ohne jedes mal die Box neu starten zu müssen?
 
Code: 
multid -s; sleep 10; multid
Oder hängt der chrony?

Gruß
Oliver
 
Glaube ich nicht, das es am Chrony liegt. Ich hatte diese "Hänger" vorher auch bei WebDav (dem von AVM). Weil ich den aber nicht brauche, habe ich den letztens (vor ca. zwei-drei Wochen) schon removed, in der Höffnung, dass es dann besser geht.
Auch habe ich beim letzen "Hänger" Chrony mal gekillt (weil dieser eben den letzen Onlinechanged-Eintrag im Log hinterlassen hatte), und manuell neu gestartet, was aber nichts gebracht hatte.

Könnte es eventuell etwas damit zu tun haben, dass die Box die Syslog-Einträge nicht schnell genug wegschreiben kann (liegt bei mir auf dem Stick)? Habe den gestern (weil ich mir langsam nicht mehr zu helfen weiß) wieder umgestellt auf "Standard", also in den Ram der Box (25 kB klein) .

EDIT:
Oder hat das was mit diesen beiden Sleep-Prozessen zu tun, die ich in ps sehe (diese weiß ich nämlich nicht zuzuordnen):

Code: 
root@fritz:/var/mod/root# ps
  PID USER       VSZ STAT COMMAND
    1 root      1148 S    init
...
 3928 root      1148 S    init
 3952 root      1180 S    /sbin/chronyd -f /var/tmp/chrony.conf
 6541 root      1164 S    syslogd -L -C25
15824 root      1044 S <  /sbin/udevd --daemon
15938 root      3044 S    hostapd -B /var/tmp/wlan_ath0_topology
16291 root      3424 S N  smbd -s /mod/etc/samba/smb.conf
16804 root      1168 S    dropbear -i -s -R
16805 root      1156 S    -sh
[COLOR="red"]16885 root      1132 S    sleep 59
16888 root      1132 S    sleep 60[/COLOR]
16889 root      1144 R    ps
20070 root      1140 S    httpd-webcfg -P /var/run/webcfg.pid -p 91 -c /mod/etc/webcfg.conf -h /usr/mww/

Diese habe ich noch bei keinem anderen in ps gesehen...
 
Zuletzt bearbeitet:
Um antworten zu können musst du eingeloggt sein.

Zurzeit aktive Besucher

Gesamt: 821 (Mitglieder: 36, Gäste: 785)

Neueste Beiträge

Statistik des Forums

Themen
244,870
Beiträge
2,219,873
Mitglieder
371,590
Neuestes Mitglied
Frank_W
Holen Sie sich 3CX - völlig kostenlos!
Verbinden Sie Ihr Team und Ihre Kunden Telefonie Livechat Videokonferenzen

Gehostet oder selbst-verwaltet. Für bis zu 10 Nutzer dauerhaft kostenlos. Keine Kreditkartendetails erforderlich. Ohne Risiko testen.

3CX
Für diese E-Mail-Adresse besteht bereits ein 3CX-Konto. Sie werden zum Kundenportal weitergeleitet, wo Sie sich anmelden oder Ihr Passwort zurücksetzen können, falls Sie dieses vergessen haben.
Ihr E-Mail-Adresse verifizieren

Ihr E-Mail-Adresse verifizieren

Wir haben Ihnen eine E-Mail geschickt. Klicken Sie auf die Schaltfläche im E-Mail-Text, um Ihre E-Mail-Adresse zu verifizieren – (Können Sie diese nicht finden können, dann überprüfen Sie Ihren Spam-Ordner).

IPPF im Überblick

Neueste Beiträge

Direktlinks Telefonanlage

Website-Sponsoren

3CX sponsor
KONTAKTIEREN SIE UNS BEI INTERESSE
| Style by ThemeHouse
XenPorta 2 PRO © Jason Axelrod of 8WAYRUN
Oben Unten
Zurück