DTMFBox läßt Fritz-Box neu starten

[miwu]

Hallo,

ich habe mir vor einer guten Woche Freetz auf meine 7170 gespielt und bin soweit auch sehr zufrieden damit.

Ein Problem bleibt leider noch: Ich möchte mit DTMFBox für mich Callback einrichten. Ich habe alle Einstellungen in der GUI so vorgenommen, dass der Callback prinzipiell auch funktioniert. Leider stürzt meine Fritz-Box aber immer nach ein paar Minuten nach dem Start von DTMFBox ab. Manchmal startet sich die ganze Box neu, manchmal gibt es aber auch nur ein PPPOE-Timeout und die Synchronisation beginnt neu. Besonders zweiteres ist sehrt ärgerlich, da damit auch alle VOIP-Nummern unterbrochen werden.

Ich habe schon herausgefunden, dass die ständigen Neustarts nicht mehr auftreten, wenn ich die Datei dtmfbox.diff unter /Var/tmp/flash lösche, sie wird aber bei jedem Start neu angelegt.

Gibt es noch irgendwo etwas zu konfigurieren? Könnte vielleicht einfach auch nur das Filesystem voll sein? Wie könnte ich das herausfinden? Ein df -k zeigt nix verwertbares an.

Vielen Dank!

miwu

 

[Darkyputz]

hast du mal deinen ram im auge behalten? nicht das die arme box wegen platzmangels im ram neu startet???
swap dazunhemen vielleicht?

 

[miwu]

Hi Darkyputz,

vielen Dank für Deine Antwort. Der RAM wird nach einem Neustart der Box innerhalb von ca. 14 Stunden bis auf 2000k vollständig belegt. Ich denke, das wird auch des Rätsels Lösung sein.

In Freetz gibts bei den Paketen einen Swap-Dienst. Reicht es, diesen Dienst zu starten? Oder sollte ich besser ein Swap-File auf einem USB-Stick anlegen?

Vielen Dank!

Miwu

 

[McNetic]

Du musst auf jeden Fall ein Swap-File oder eine Swap-Partition auf dem USB-Stick anlegen, sonst funktioniert der Swap-Dienst natürlich nicht. Wenn der Speicher allerdings wirklich immer voller läuft, wird das die Zeitspanne bis zum Reboot lediglich verlängern. Die wirkliche Ursache zu suchen dürfte also zielführender sein.

 

[miwu]

Hi mcnetic,

ich glaube, ich bin schon ein Stück weiter. Es sieht so aus, als ob die DTMXBox manchmal bestehende Callback-Verbindungen nicht sauber wieder trennt. Die bestehenden Verbindungen bleiben dann immernoch im DTMF-Status stehen und jede von Ihnen hat einen eigenen Prozess, der RAM belegt.

Ich werde das mal weiter beobachten, vielleicht bekomme ich ja raus, wann das auftritt, denn nach einem Restart der DTMF-Box werden die Verbindungen nun sauber getrennt.

Miwu

 

[miwu]

Hi,

ich habe mal versucht, das Problem ein wenig einzugrenzen und mir eine Freetz-Firmware gebaut, in der nur der Callmonitor und die DTMF-Box enthalten sind. Leider tritt das Problem immernoch auf, die Box startet alle paar Stunden neu, was sie mit meiner alter 2.4-er Kernel-Software und dem Callmonitor 1.9 nicht tat. Den Callmonitor darf ich nicht abschalten, wenn ich die DTMFBox abschalte bleibt das Problem aber bestehen.

Wie könnt ich weiter vorgehen, um die Ursache des Problems zu finden? Die Logs im AVM-Interface sehen bei den Abstürzen immer so aus:

06.07.08 21:51:55 Internetverbindung wurde erfolgreich hergestellt. IP-Adresse: 87.160.158.4, DNS-Server: 217.237.151.51 und 217.237.149.205, Gateway: 217.0.116.242, Breitband-PoP: BERX47-erx
06.07.08 21:51:50 DSL ist verfügbar (DSL-Synchronisierung besteht mit 16279/1183 kbit/s).
06.07.08 21:51:33 DSL-Synchronisierung beginnt (Training).
06.07.08 21:51:29 Internetverbindung wurde getrennt.
06.07.08 21:51:29 DSL antwortet nicht (Keine DSL-Synchronisierung).

Jede Idee ist willkommen.

Dank!

Miwu

 

[Silent-Tears]

Das avm-log bringt nicht viel. Syslog wäre da ein wenig sinnvoller. Das mit in die Box und über ssh mit logread -f konstant ausgeben lassen.

 

[miwu]

Alles klar, mache ich morgen und poste dann meine Erkenntnisse hier.

Danke!

Miwu

 

[miwu]

So, ich habe jetzt mal den Syslog mitlaufen lassen. Folgende Ausgaben kamen:

07-07-2008    08:05:48    User.Error    192.168.142.88    Jul  7 08:07:50 telefon[510]: SIGCHLD received!
07-07-2008    08:05:23    User.Error    192.168.142.88    Jul  7 08:07:25 dsld[502]: VPN led value = 0
07-07-2008    08:05:06    User.Error    192.168.142.88    Jul  7 08:07:08 multid[493]: 0.0.0.0:2050: failed to send UDP-datagram to 192.168.180.2:53 - Network is unreachable (128)
07-07-2008    08:05:06    User.Error    192.168.142.88    Jul  7 08:07:08 multid[493]: 0.0.0.0:2050: failed to send UDP-datagram to 192.168.180.1:53 - Network is unreachable (128)
07-07-2008    08:04:49    User.Error    192.168.142.88    Jul  7 08:06:51 dsld[502]: VPN led value = 0
07-07-2008    08:04:46    User.Error    192.168.142.88    Jul  7 08:06:48 multid[493]: 0.0.0.0:2050: failed to send UDP-datagram to 192.168.180.1:53 - Network is unreachable (128)

Die zugehörigen Logs der Fritz-Box-Oberfläche sehen so aus:

[URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2724%27%29"]07.07.08 08:07:27 Internetverbindung wurde erfolgreich hergestellt. IP-Adresse: 87.160.148.222, DNS-Server: 217.237.151.51 und 217.237.149.205, Gateway: 217.0.116.242, Breitband-PoP: BERX47-erx[/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2711%27%29"]07.07.08 08:07:23 DSL ist verfügbar (DSL-Synchronisierung besteht mit 16185/1183 kbit/s).[/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2712%27%29"]07.07.08 08:07:06 DSL-Synchronisierung beginnt (Training).[/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2710%27%29"]07.07.08 08:07:02 DSL antwortet nicht (Keine DSL-Synchronisierung).[/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2723%27%29"]07.07.08 08:06:56 Internetverbindung wurde getrennt.[/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2741%27%29"]07.07.08 08:06:56 PPPoE-Fehler: Zeitüberschreitung. [/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2711%27%29"]07.07.08 08:06:49 DSL ist verfügbar (DSL-Synchronisierung besteht mit 16244/1183 kbit/s).[/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2712%27%29"]07.07.08 08:06:32 DSL-Synchronisierung beginnt (Training).[/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2723%27%29"]07.07.08 08:06:28 Internetverbindung wurde getrennt.[/URL]
 [URL="http://javascript%3Cb%3E%3C/b%3E:Eventhelp%28%2710%27%29"]07.07.08 08:06:28 DSL antwortet nicht (Keine DSL-Synchronisierung).[/URL]

Kann jemand etwas daraus erkennen?

Vielen Dank!

Miwu

 

[Silent-Tears]

Ein bisschen mehr solltest du schon posten. Daraus ersieth man kaum etwas.

 

[miwu]

Hallo,

das sind die gesamten Logs des Vormittags. Kann man das Logging denn noch irgendwie erweitern sodass es detaillierter wird?

07.07.2008 07:57    User.Notice    192.168.142.88    Jul  7 07:59:16 root: Hallo Welt
07.07.2008 07:57    Cron.Notice    192.168.142.88    Jul  7 08:00:01 crond[582]: USER root pid 2540 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 08:04    User.Error    192.168.142.88    Jul  7 08:06:48 multid[493]: 0.0.0.0:2050: failed to send UDP-datagram to 192.168.180.1:53 - Network is unreachable (128)
07.07.2008 08:04    User.Error    192.168.142.88    Jul  7 08:06:51 dsld[502]: VPN led value = 0
07.07.2008 08:05    User.Error    192.168.142.88    Jul  7 08:07:08 multid[493]: 0.0.0.0:2050: failed to send UDP-datagram to 192.168.180.1:53 - Network is unreachable (128)
07.07.2008 08:05    User.Error    192.168.142.88    Jul  7 08:07:08 multid[493]: 0.0.0.0:2050: failed to send UDP-datagram to 192.168.180.2:53 - Network is unreachable (128)
07.07.2008 08:05    User.Error    192.168.142.88    Jul  7 08:07:25 dsld[502]: VPN led value = 0
07.07.2008 08:05    User.Error    192.168.142.88    Jul  7 08:07:50 telefon[510]: SIGCHLD received!
07.07.2008 08:07    Cron.Notice    192.168.142.88    Jul  7 08:10:01 crond[582]: USER root pid 3643 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 08:17    Cron.Notice    192.168.142.88    Jul  7 08:20:01 crond[582]: USER root pid 3850 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 08:30    Cron.Notice    192.168.142.88    Jul  7 08:30:01 crond[582]: USER root pid 3855 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 08:36    User.Error    192.168.142.88    Jul  7 08:36:25 dsld[502]: VPN led value = 0
07.07.2008 08:36    User.Error    192.168.142.88    Jul  7 08:36:59 dsld[502]: VPN led value = 0
07.07.2008 08:39    User.Error    192.168.142.88    Jul  7 08:39:48 dsld[502]: VPN led value = 0
07.07.2008 08:40    Cron.Notice    192.168.142.88    Jul  7 08:40:01 crond[582]: USER root pid 3873 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 08:45    User.Error    192.168.142.88    Jul  7 08:45:24 telefon[510]: SIGCHLD received!
07.07.2008 08:50    Cron.Notice    192.168.142.88    Jul  7 08:50:01 crond[582]: USER root pid 719 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 09:00    Cron.Notice    192.168.142.88    Jul  7 09:00:01 crond[582]: USER root pid 791 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 09:10    Cron.Notice    192.168.142.88    Jul  7 09:10:01 crond[582]: USER root pid 794 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 09:20    Cron.Notice    192.168.142.88    Jul  7 09:20:01 crond[582]: USER root pid 797 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 09:30    Cron.Notice    192.168.142.88    Jul  7 09:30:01 crond[582]: USER root pid 800 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 09:33    User.Error    192.168.142.88    Jul  7 09:33:49 dsld[502]: VPN led value = 0
07.07.2008 09:34    User.Error    192.168.142.88    Jul  7 09:34:19 dsld[502]: VPN led value = 0
07.07.2008 09:40    Cron.Notice    192.168.142.88    Jul  7 09:40:01 crond[582]: USER root pid 813 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 09:50    Cron.Notice    192.168.142.88    Jul  7 09:50:02 crond[582]: USER root pid 816 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 10:00    Cron.Notice    192.168.142.88    Jul  7 10:00:01 crond[582]: USER root pid 819 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 10:10    Cron.Notice    192.168.142.88    Jul  7 10:10:01 crond[582]: USER root pid 822 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 10:17    User.Error    192.168.142.88    Jul  7 10:17:09 telefon[510]: SIGCHLD received!
07.07.2008 10:20    Cron.Notice    192.168.142.88    Jul  7 10:20:01 crond[582]: USER root pid 1507 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 10:30    Cron.Notice    192.168.142.88    Jul  7 10:30:01 crond[582]: USER root pid 1593 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 10:40    Cron.Notice    192.168.142.88    Jul  7 10:40:01 crond[582]: USER root pid 1596 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 10:50    Cron.Notice    192.168.142.88    Jul  7 10:50:01 crond[582]: USER root pid 1599 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 11:00    Cron.Notice    192.168.142.88    Jul  7 11:00:01 crond[582]: USER root pid 1602 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 11:01    User.Error    192.168.142.88    Jul  7 11:01:20 dsld[502]: VPN led value = 0
07.07.2008 11:03    User.Error    192.168.142.88    Jul  7 11:03:17 dsld[502]: VPN led value = 0
07.07.2008 11:03    User.Error    192.168.142.88    Jul  7 11:03:50 dsld[502]: VPN led value = 0
07.07.2008 11:04    User.Error    192.168.142.88    Jul  7 11:04:16 dsld[502]: VPN led value = 0
07.07.2008 11:10    Cron.Notice    192.168.142.88    Jul  7 11:10:01 crond[582]: USER root pid 1625 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 11:20    Cron.Notice    192.168.142.88    Jul  7 11:20:01 crond[582]: USER root pid 1628 cmd /var/tmp/flash/ipcheck.sh
07.07.2008 11:22    User.Error    192.168.142.88    Jul  7 11:22:14 telefon[510]: SIGCHLD received!
07.07.2008 11:26    User.Notice    192.168.142.88    Jul  7 11:26:08 root: test
07.07.2008 11:26    User.Notice    192.168.142.88    Jul  7 11:26:22 root: test
07.07.2008 11:30    Cron.Notice    192.168.142.88    Jul  7 11:30:01 crond[582]: USER root pid 2193 cmd /var/tmp/flash/ipcheck.sh

Das Script unter /var/tmp/flash/ipcheck.sh prüft alle 10 Minuten, ob bei mir im Netz noch wichtige IP-Adressen erreichbar sind.

Danke!

Miwu

 

[matze1985]

ich denke mal es wäre am interessantesten, wenn du uns nen log stellen könntest vom Moment des Reboots.


Hast du die Möglichkeit ins Netzwerk zu loggen und dann den Reboot zu provozieren? Wie sieht es denn mit dem Ram der Box aus?

 

[miwu]

Hi Matze,

die Logs sind genauso entstanden, ich habe den syslogd so gestartet, dass er auf meinen Server loggt, dort empfängt Kiwi die Logs. Die Box startet nur ganz selten neu, sie verliert eigentliich immer nur die DSL-Verbindung, synchronisiert sich neu mit der Gegenstelle und stellt die Internetverbindung wieder her.

Ob es etwas bringt, wenn ich mal den dsld mit einer Debug-Option starte, doch wo könnte ich das einstellen?

Miwu

 

[Silent-Tears]

Du könntest den dsld manuell neu starten. "dsld -h" gibt dir glaube ich die Parameterliste.

 

[bodega]

Es sieht so aus, als ob die DTMXBox manchmal bestehende Callback-Verbindungen nicht sauber wieder trennt. Die bestehenden Verbindungen bleiben dann immernoch im DTMF-Status stehen und jede von Ihnen hat einen eigenen Prozess, der RAM belegt.

Hi Miwu,

ist das zufällig eine VoIP-Verbindung? Das hängt dann oft mit NAT zusammen und die Verbindung sollte nach 30sek zwangsgetrennt werden. Wenn dies jedoch bei CAPI auftritt, ist oft die "Trägheit" der Skripte schuld. Manchmal ist der Benutzer schneller als die "langsame" Box .

Das sollte mit v0.5 der Vergangenheit angehören, so wie ich hoffe. Es läuft zumindest sehr schnell. Auch der Speicherverbrauch hält sich bei v0.5 in Grenzen (~ 4-5 MB). Da eSpeak auch einen Teil Speicher wegnimmt, sollte man dies auch nicht unterschätzen. Dafür gibt es dann den Webstream.

 

[miwu]

Hi Marco,

ja, das waren VOIP-Verbindungen, CAPI war nie bei den hängenden Verbindungen dabei.

Wann kommt denn V 0.5 raus oder müßte ich einfach ein neues Image von Freetz builden?

Danke!

Miwu