Asterisk - Verbindungsabbruch

[blubbersuelze]

Hallo zusammen,

Ich habe an meinem Asterisk Server immer nach ca 2,5min Telefonat einen Verbindungsabbruch.

Die Hardware: eine virtuelle Maschine mit 2 Cores und 4GB RAM, auf einem Host welcher mehr als genug freie Ressourcen hat. (CPU-Last bei ca 10%, RAM Nutzung von ca 6GB bei gesamt 32GB RAM und Load von ca. 2 bei 8 Cores)

OS: Debian Squeeze mit Asterisk 1.6 und Asterisk_Chan_capi
(Wheezy hat Asterisk 1.8, aber Chan_CAPI kann damit nicht mehr)

Die virtuelle Maschine verbindet zu ISDN mittels einer Fritzcard USB

Telefonate können getätigt und auch angenommen werden, leider bricht das Telefonat immer nach ca 2,5Min ab.

Der Client ist ein Smartphone.

Das WLAN verbindet mit 300Mbit/s n-Draft und das Smartphone verbindet mit >70Mb/s lt. Gerät. Es sind keine Abbrüche der Verbindung, auch sind nur 4 Smartphones im WLAN eingewählt, sonst nichts.

Ich dachte erst das es an der VOIP-App liegt, allerdings habe ich mit anderen VOIP-Apps den gleichen Effekt.

Auf der Netzwerkstrecke ist keine Firewall dazwischen.

Leider weiß ich nicht wonach ich genau suchen soll, im Internet finde ich auch nichts brauchbares an Informationen.

Ich habe mal das Logfile angehangen. Dafür habe ich Asterisk gestoppt, das Logfile gelehrt, Asterisk gestartet, ein Telefonat getätigt bis zum Abbruch und Asterisk wieder gestoppt.

Für jede Hilfe wäre ich dankbar.

mfg.
blubbersuelze

 

[wildzero]

IAX2 Softphones? Welche?

[Apr 13 20:05:18] DEBUG[8095] chan_iax2.c: Immediately destroying 667, having received hangup

Den iax2 debug noch anmachen. Um zu sehen was hier passiert. Aber iax2 debuggen ist schon eher ne' exotisch sache

Gleiches Ergebniss mit SIP? Dann auch eine SIP debug dazu.

 

[blubbersuelze]

Verwende Zoiper als Softphoneapp.

Werde es mit SIP testen und mich dann wieder melden.

 

[blubbersuelze]

so .. einmal mit SIP

und aktiviertem Debug für SIP und für CAPI.

Dieses mal kam kein Abbruch, aber nach ca 2,5min konnte man die Gegenseite nicht mehr hören.

Hier der Link zur Datei: http://tommysworld.homenet.org/full.zip

Ich hoffe das das Log euch hilft mir zu helfen.

danke im voraus

 

[abw1oim]

eine virtuelle Maschine

Spätestens in Verbindung mit ISDN an sich eine ganz schlechte Idee, aber sei's drum:

Im ersten Log ist mir noch aufgefallen:

[Apr 13 20:05:08] DEBUG[8098] res_timing_timerfd.c: Expected to acknowledge 1 ticks but got 10 instead

- direkt ndanach erfolgt der Abbruch.

Im zweiten Log wiederholt sich das:

[Apr 15 22:50:01] DEBUG[3389] res_timing_timerfd.c: Expected to acknowledge 1 ticks but got 3 instead

mit dem - zeitlich - direkt nachgelagerten Effekt

[Apr 15 22:50:01] VERBOSE[3410] chan_capi_utils.c: [Apr 15 22:50:01]        > ISDN1#02: B3count is full, dropping packet.
...
[Apr 15 22:50:02] VERBOSE[3410] chan_capi_utils.c: [Apr 15 22:50:02]        > ISDN1#02: too much voice to send for NCCI=0x10401

Und einige Sekunden später gibt die CAPI dann auf:

[Apr 15 22:50:29] VERBOSE[3396] chan_capi_utils.c: [Apr 15 22:50:29]     -- ISDN1#02: info element DISCONNECT
[Apr 15 22:50:29] VERBOSE[3396] chan_capi_utils.c: [Apr 15 22:50:29]     -- ISDN1#02: Disconnect case 3
...
[Apr 15 22:50:29] VERBOSE[3396] chan_capi_utils.c: [Apr 15 22:50:29]     -- ISDN1#02: info element CAUSE 80 90

und nun folgt Asterisk selbst:

[Apr 15 22:50:29] DEBUG[3410] channel.c: Didn't get a frame from channel: CAPI/ISDN1#02/8704-0
[Apr 15 22:50:29] DEBUG[3410] channel.c: Bridge stops bridging channels CAPI/ISDN1#02/8704-0 and IAX2/Thomas-1767
...
[Apr 15 22:50:29] DEBUG[3410] channel.c: Hanging up channel 'IAX2/Thomas-1767'
[Apr 15 22:50:29] DEBUG[3410] chan_iax2.c: We're hanging up IAX2/Thomas-1767 now...
[Apr 15 22:50:29] VERBOSE[3410] chan_iax2.c: [Apr 15 22:50:29]     -- Hungup 'IAX2/Thomas-1767'
[Apr 15 22:50:29] DEBUG[3410] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Apr 15 22:50:29] DEBUG[3410] pbx.c: Spawn extension (capi-in,8704,1) exited non-zero on 'CAPI/ISDN1#02/8704-0'
[Apr 15 22:50:29] VERBOSE[3410] pbx.c: [Apr 15 22:50:29]   == Spawn extension (capi-in, 8704, 1) exited non-zero on 'CAPI/ISDN1#02/8704-0'

Also: IAX2 ist hier nicht der Verursacher, das ist die CAPI und - streng genommen - das fehlgehende Timing.
Ein Lösungsszenario bei Weiternutzung der Virtuellen Maschine könnte der Austausch der Timer-Module sein. Im Moment wird res_timing_timerfd.so benutzt. Im ersten Schritt könnte zu res_timing_pthread.so gewechselt werden. Dazu ist die modules.cof entsprechend anzupassen

;
; Only load one timing interface.  If DAHDI is available, use that as it will
; provide the best results.
;
noload => res_timing_dahdi.so
;noload => res_timing_pthread.so
noload => res_timing_timerfd.so

Danach kannst Du (nach einem entsprechenden Reload) neu testen. Mit ein wenig Glück löst das bereits Dein Problem.
Sonst folgt Alternative 2:
res_timing_dahdi.so muss verwendet werden. Dazu müssen die dahdi-Sourcen kompiliert und anschließend das dahdi_dummy-Modul geladen werden. Danach Asterisk neu übersetzen und das zu ladende Timer-Modul in modules.conf entsprechend anpassen.

 

[blubbersuelze]

danke für die Informationen,

ich werde sobald als möglich die Vorschläge testen und mich dann wieder melden.
(kann nach Ostern sein)

 

[blubbersuelze]

Hallo,

so ich habe es probiert,

auch mit Asterisk-dahdi

allerdings geht das mit Asterisk dahdi ebenso nicht.

Laut http://docs.tzafrir.org.il/dahdi-linux/README.html wird meine Fritzcard USB von dahdi auch nicht unterstützt,
so das kein dahdi-Device erstellt wird so das es genutzt werden kann.

Weitere Ideen?


mfg.
blubbersuelze

 

[abw1oim]

Das war nicht mein Rat: Du solltest ggf. dahdi_dummy verwenden, um res_timing_dahdi.so nutzen zu können, nicht etwa um Dein Device per DAHDI zu betreiben. Das arbeitet ja schon mal grundsätzlich mit CAPI zusammen ...

 

[blubbersuelze]

Hallo nochmal,

so habe mal das ganze System auf Hardware umgezogen,
um die virtuelle Maschine als mögliche Fehlerquelle auszuschließen.

Intel Atom D510 mit 2x 1,6GHz
2GB DDR2 RAM
das ISDN-Device ist nach wie vor eine Fritzcard USB 2.1

Das System ist Debian Squeeze mit Backports und Asterisk 1.8 und asterisk-chan-capi 1.1.6


Nach ca 3min hört der Gegenpart mich aber trotzdem nicht mehr :-(

Ich hoffe es da weitere Hilfen gibt, danke schon einmal im voraus

mfg.
blubbersuelze

 

[blubbersuelze]

Ich habe es mal analysiert und auseinander genommen,
es scheint ein generelles Problem mit CAPI zu sein.
Irrelevant ob in einer VM oder auf Hardware läuft.

Hier die Auszüge des Asterisk Log:

das hier kommt immer wieder:

[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_IND ID=003 #0x7cba LEN=0030
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_RESP ID=003 #0x7cba LEN=0014
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] CAPI: ApplId=0x0003 Command=0x86 SubCommand=0x82 MsgNum=0x7cbb NCCI=0x00010501
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_IND ID=003 #0x7cbb LEN=0030
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_RESP ID=003 #0x7cbb LEN=0014
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_REQ ID=003 #0x1ede LEN=0030
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_REQ ID=003 #0x1edf LEN=0030
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_REQ ID=003 #0x1ee0 LEN=0030
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_REQ ID=003 #0x1ee1 LEN=0030
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_REQ ID=003 #0x1ee2 LEN=0030
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_REQ ID=003 #0x1ee3 LEN=0030
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_REQ ID=003 #0x1ee4 LEN=0030
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56]        > ISDN1#02: B3count is full, dropping packet.
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] CAPI: ApplId=0x0003 Command=0x86 SubCommand=0x82 MsgNum=0x7cbc NCCI=0x00010501
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_IND ID=003 #0x7cbc LEN=0030
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_RESP ID=003 #0x7cbc LEN=0014
[Apr 28 23:07:56] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:07:56]        > ISDN1#02: B3count is full, dropping packet.
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] CAPI: ApplId=0x0003 Command=0x86 SubCommand=0x82 MsgNum=0x7cbd NCCI=0x00010501
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_IND ID=003 #0x7cbd LEN=0030
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] DATA_B3_RESP ID=003 #0x7cbd LEN=0014
[Apr 28 23:07:56] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:07:56] CAPI: ApplId=0x0003 Command=0x86 SubCommand=0x81 MsgNum=0x1ede NCCI=0x00010501

und dann kommt das hier, sobald die Gegenseite mich nicht mehr hört, anschließend wurde aufgelegt.

[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DATA_B3_IND ID=003 #0x8c8b LEN=0030
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DATA_B3_RESP ID=003 #0x8c8b LEN=0014
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x86 SubCommand=0x82 MsgNum=0x8c8c NCCI=0x00010501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DATA_B3_IND ID=003 #0x8c8c LEN=0030
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DATA_B3_RESP ID=003 #0x8c8c LEN=0014
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x08 SubCommand=0x82 MsgNum=0x8c8d NCCI=0x00000501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] INFO_IND ID=003 #0x8c8d LEN=0015
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] INFO_RESP ID=003 #0x8c8d LEN=0012
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17]     -- ISDN1#02: info element DISCONNECT
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17]     -- ISDN1#02: Disconnect case 1
[Apr 28 23:09:17] VERBOSE[21072] frame.c: [Apr 28 23:09:17]     -- chan_capi queue frame:Control (4) SUBCLASS: Hangup (1) ] [ISDN1#02]
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x08 SubCommand=0x82 MsgNum=0x8c8e NCCI=0x00000501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] INFO_IND ID=003 #0x8c8e LEN=0017
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] INFO_RESP ID=003 #0x8c8e LEN=0012
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17]     -- ISDN1#02: info element PI 82 88
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17]        > ISDN1#02: In-band information available
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x08 SubCommand=0x82 MsgNum=0x8c8f NCCI=0x00000501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] INFO_IND ID=003 #0x8c8f LEN=0017
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] INFO_RESP ID=003 #0x8c8f LEN=0012
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17]     -- ISDN1#02: info element CAUSE 80 90
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x86 SubCommand=0x82 MsgNum=0x8c90 NCCI=0x00010501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DATA_B3_IND ID=003 #0x8c90 LEN=0030
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DATA_B3_RESP ID=003 #0x8c90 LEN=0014
[Apr 28 23:09:17] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:09:17]   == ISDN1#02: CAPI Hangingup for PLCI=0x501 in state 2
[Apr 28 23:09:17] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:09:17]     -- ISDN1#02: activehangingup (cause=16) for PLCI=0x501
[Apr 28 23:09:17] VERBOSE[21082] chan_capi_utils.c: [Apr 28 23:09:17] DISCONNECT_B3_REQ ID=003 #0x2bbc LEN=0013
[Apr 28 23:09:17] VERBOSE[21042] chan_capi_utils.c: [Apr 28 23:09:17]        > chan_capi devicestate requested for ISDN1#02/02612961248 is 'Not in use'
[Apr 28 23:09:17] VERBOSE[21042] chan_capi_utils.c: [Apr 28 23:09:17]        > chan_capi devicestate requested for ISDN1#02/02612961248 is 'Not in use'
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x84 SubCommand=0x81 MsgNum=0x2bbc NCCI=0x00010501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DISCONNECT_B3_CONF ID=003 #0x2bbc LEN=0014
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x84 SubCommand=0x82 MsgNum=0x8c91 NCCI=0x00010501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DISCONNECT_B3_IND ID=003 #0x8c91 LEN=0015
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DISCONNECT_B3_RESP ID=003 #0x8c91 LEN=0012
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DISCONNECT_REQ ID=003 #0x2bbd LEN=0013
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x04 SubCommand=0x81 MsgNum=0x2bbd NCCI=0x00000501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DISCONNECT_CONF ID=003 #0x2bbd LEN=0014
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] CAPI: ApplId=0x0003 Command=0x04 SubCommand=0x82 MsgNum=0x8c92 NCCI=0x00000501
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DISCONNECT_IND ID=003 #0x8c92 LEN=0014
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17] DISCONNECT_RESP ID=003 #0x8c92 LEN=0012
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17]        > ISDN1#02: CAPI INFO 0x3490: Normal call clearing
[Apr 28 23:09:17] VERBOSE[21072] chan_capi_utils.c: [Apr 28 23:09:17]   == ISDN1#02: Interface cleanup PLCI=0x501

verwendet werden:
Asterisk 1.8
asterisk-chan-capi 1.1.6
Fritzcard-USB 0.9.2 (http://www.joonet.de/sources/fcusb2-driver/src/)

Hardware:
Intel Atom D510 2 Cores mit je 1,6GHz
1GB RAM
AVM Fritzcard USB v2.1

vlt. weiß jemand was ich mit den CAPI Sourcen, oder an anderen Stellen machen muss , das CAPI stabil läuft.


mfg.
blubbersuelze