Periodisch nicht erreichbar am Anlagenanschluss / 4BRI-8M *** CPU TRAPPED *** ???

[magistratusx]

Hallo,

ich habe folgendes Problem. Ich habe bei einem Kunden einen Asterisk-Server mit einer Eicon Diva 4BRI Karte, die mit Port 1 und 2 jeweils an einem NTBA am Anlagenanschluss hängt. Nach dem Start des Servers funktioniert auch erstmal alles wunderbar. Allerdings ist es nach einem Tag nicht mehr möglich raus zu telefonieren. Und auch eingehende Anrufe werden nicht mehr an die Asterisk signalisiert. Die Diva ist wie folgt eingestellt:

* Please select D-channel protocol: ETSI - Europe/other countries, Euro-ISDN (ETSI-DSS1)
* Please select NT-2 (Direct Dial In, Direct Inward Dialing) mode: No
[...]
* Please select D-channel layer 2 activation policy: Deactivation only by other side (default)
[...]
* Please configure trunk operation mode: Point to Point
* Please configure amount of TEI's: one TEI (default)
[...]​

Da der Fehler periodisch auftritt, sich aber nichts in den Logs findet und auch ein 'capi debug' mir nichts aufschlussreiches geliefert hat, außer dass es beim Rauswählen ein Layer 2 Problem und dann ein Congestion gibt, habe ich die Vermutung, dass der Anschluss selbst das Problem verursacht.

Weiß jemand, ob manche Telcos in regelmäßigen Intervallen den D-Channel deaktivieren? Und wenn das so ist, wie reagiert die Karte dann auf die Einstellung, die ich oben angegeben habe? Was bewirkt ggfs. "D-channel layer 2 activation policy: Always active" ?

 

[Ottone]

Andere - möglicherweise blöde - Frage: Warum DDI=no wenn Du point-to-point machst?

 

[magistratusx]

Weil ich die Einstellung für unnötig erachtet habe. Die Rufnummer wird vom Dialplan um die Kopfnummer gekürzt, so dass ich die DIDs nicht einzeln brauche. Das funktioniert ja auch ganz gut, wenn die Karte denn läuft.

 

[armincm]

wenn man nicht mehr raus telefonieren kann, so sollte es eine fehlermeldung geben. Ein log mit capi debug und set verbose 5 zeigt dies dann. Wenn es ein Problem auf dem D-Kanal ist, sollte "divactrl mlog" benutzt werden, um dies zu zeigen.

Armin

 

[magistratusx]

Folgendes steht im Asterisk-Log von heute früh, als das Problem wieder aufgetreten ist.

-- snip --
Aug 12 08:51:40 VERBOSE[5606] logger.c: -- Executing Dial("SIP/21-081a9408", "CAPI/g1/<Nummer>/b||gTW") in new stack
Aug 12 08:51:40 WARNING[3389] chan_capi.c: 4BRI-2#02: conf_error 0x3001 PLCI=0x2 Command=CONNECT_CONF,0x8483
Aug 12 08:51:40 VERBOSE[5606] logger.c: -- Called g1/<Nummer>/b
Aug 12 08:51:40 VERBOSE[5606] logger.c: -- CAPI/4BRI-2#02/<Nummer>-7 is busy
Aug 12 08:51:40 VERBOSE[5606] logger.c: == Everyone is busy/congested at this time (1:1/0/0)
-- snip --

Mehr habe ich zur Zeit nicht.

 

[magistratusx]

Das Problem scheint gelöst zu sein. Nachdem ich die "D-Channel layer 2 activation policy" auf "Always active" umgestellt habe läuft die Anlage jetzt seit zwei Tagen scheinbar stabil. Mal schauen, ob das auch so bleibt. ;-)

 

[magistratusx]

Schade aber auch. Das Problem besteht weiterhin. Allerdings findet sich, nachdem ich das Debugging des Diva-Treibers eingeschaltet habe, auch was im Syslog:

Aug 19 00:01:26 pbx divas: 150:20:59.914 F 2 Diva Server 4BRI-8M PCI: ***************** end of XLOG *****************
Aug 19 00:01:26 pbx 'divas: debug usermode helper' +----------------------------- ADAPTER DUMP END   -----------------------+
Aug 19 00:01:28 pbx 'divas: debug usermode helper' +------------------------------------------------------------------------+
Aug 19 00:01:28 pbx 'divas: debug usermode helper' | adapter core dump recovered and saved to /var/log/diva_dump1.txt |
Aug 19 00:01:28 pbx 'divas: debug usermode helper' +----------------------------- ADAPTER DUMP START -----------------------+
Aug 19 00:01:28 pbx divas: Tue Aug 19 00:01:26 CEST 2008
Aug 19 00:01:28 pbx divas: <BR>(divas4linux_SOURCE-108.84-1.i386.rpm)
Aug 19 00:01:28 pbx divas: Diva Server 4BRI-8M PCI 2557
Aug 19 00:01:28 pbx divas:
Aug 19 00:01:28 pbx divas:  -----------------------------------------------------
Aug 19 00:01:28 pbx divas:   ditrace, BUILD (108-24[108-120]-Mar 10 2008-15:10:46)
Aug 19 00:01:28 pbx divas:  ------------------------------------------------------
Aug 19 00:01:28 pbx divas:    0:00:00.000 01 - DIDD(3.0)
Aug 19 00:01:28 pbx divas:    0:00:00.000 02 - DIVAS(2.0)
Aug 19 00:01:28 pbx divas:    0:00:00.000 03 - MAINT(3.1)
Aug 19 00:01:28 pbx divas:    0:00:01.532 04 - ADAPTER:1 SN:2557
Aug 19 00:01:28 pbx divas:    0:00:01.556 05 - ADAPTER:2 SN:2557-2
Aug 19 00:01:28 pbx divas:    0:00:01.580 06 - ADAPTER:3 SN:2557-3
Aug 19 00:01:28 pbx divas:    0:00:01.604 07 - ADAPTER:4 SN:2557-4
Aug 19 00:01:28 pbx divas:    0:00:02.079 08 - User IDI(2.0)
Aug 19 00:01:28 pbx divas:    0:00:02.096 09 - MTPX(108-344-SRC)
Aug 19 00:01:28 pbx divas:    0:00:03.110 10 - CAPI20(2.0)
Aug 19 00:01:28 pbx divas:  ------------------------------------------------------
Aug 19 00:01:28 pbx divas: ==> missing sequence 1 - 10088
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 Diva Server 4BRI-8M PCI: ***************** CPU TRAPPED *****************
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 Microcode:
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 Cause: TLB load /DBOUND
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 sr    0x1040ec03 cr    0x00001008 epc   0x8009dc50 vaddr 0x00000008
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 zero  0x00000000 at    0x80120000 v0    0x00000004 v1    0x80225794
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 a0    0x80133568 a1    0x00000028 a2    0x80274e74 a3    0x00000000
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 t0    0x800a1bb0 t1    0x74617453 t2    0x00000004 t3    0x00000000
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 t4    0x00000001 t5    0x00000001 t6    0x801c9580 t7    0x8013358c
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 s0    0x80225794 s1    0x00000004 s2    0x00000028 s3    0x80274e74
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 s4    0x80133568 s5    0x00000008 s6    0x80121bf4 s7    0x00000004
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 t8    0x00000001 t9    0x8013363e k0    0x00000000 k1    0x00000000
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 gp    0xfe7f4fe3 sp    0x80133500 s8    0x801c649c ra    0x800a1d30
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 md    0x00007480|00005761         resvd 0x00000000 class 0x00000101
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 Diva Server 4BRI-8M PCI: ************* XLOG recovery (877) *************
Aug 19 00:01:28 pbx divas: 150:21:02.043 F 2 Microcode:
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2499:544 - D-R(004) 02 01 01 05
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2499:546 - D-X(004) 02 01 01 D3
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2499:553 - D-R(004) 00 01 01 05
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2509:541 - D-X(004) 00 01 01 D3
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2509:544 - D-R(004) 02 01 01 05
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2509:546 - D-X(004) 02 01 01 D3
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2509:553 - D-R(004) 00 01 01 05
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2519:541 - D-X(004) 00 01 01 D3
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2519:545 - D-R(004) 02 01 01 05
Aug 19 00:01:28 pbx divas: 150:21:02.043 149:2519:546 - D-X(004) 02 01 01 D3

...

Aug 19 00:01:28 pbx divas: 150:21:02.052 150:1229:675 - D-R(004) 00 01 01 05
Aug 19 00:01:28 pbx divas: 150:21:02.052 150:1230:044 - Exception caused by task nr 0
Aug 19 00:01:28 pbx divas: 150:21:02.052 F 2 Diva Server 4BRI-8M PCI: ***************** end of XLOG *****************
Aug 19 00:01:28 pbx 'divas: debug usermode helper' +----------------------------- ADAPTER DUMP END   -----------------------+
Aug 19 00:01:30 pbx 'divas: debug usermode helper' +------------------------------------------------------------------------+
Aug 19 00:01:30 pbx 'divas: debug usermode helper' | adapter core dump recovered and saved to /var/log/diva_dump2.txt |
Aug 19 00:01:30 pbx 'divas: debug usermode helper' +----------------------------- ADAPTER DUMP START -----------------------+
Aug 19 00:01:30 pbx divas: Tue Aug 19 00:01:28 CEST 2008
Aug 19 00:01:30 pbx divas: <BR>(divas4linux_SOURCE-108.84-1.i386.rpm)
Aug 19 00:01:30 pbx divas: Diva Server 4BRI-8M PCI 16779773
Aug 19 00:01:30 pbx divas:
Aug 19 00:01:30 pbx divas:  -----------------------------------------------------
Aug 19 00:01:30 pbx divas:   ditrace, BUILD (108-24[108-120]-Mar 10 2008-15:10:46)
Aug 19 00:01:30 pbx divas:  ------------------------------------------------------
Aug 19 00:01:30 pbx divas:    0:00:00.000 01 - DIDD(3.0)
Aug 19 00:01:30 pbx divas:    0:00:00.000 02 - DIVAS(2.0)
Aug 19 00:01:30 pbx divas:    0:00:00.000 03 - MAINT(3.1)
Aug 19 00:01:30 pbx divas:    0:00:01.532 04 - ADAPTER:1 SN:2557
Aug 19 00:01:30 pbx divas:    0:00:01.556 05 - ADAPTER:2 SN:2557-2
Aug 19 00:01:30 pbx divas:    0:00:01.580 06 - ADAPTER:3 SN:2557-3
Aug 19 00:01:30 pbx divas:    0:00:01.604 07 - ADAPTER:4 SN:2557-4
Aug 19 00:01:30 pbx divas:    0:00:02.079 08 - User IDI(2.0)
Aug 19 00:01:30 pbx divas:    0:00:02.096 09 - MTPX(108-344-SRC)
Aug 19 00:01:30 pbx divas:    0:00:03.110 10 - CAPI20(2.0)
Aug 19 00:01:30 pbx divas:  ------------------------------------------------------
Aug 19 00:01:30 pbx divas: ==> missing sequence 1 - 10980
Aug 19 00:01:30 pbx divas: 150:21:04.143 F 2 Diva Server 4BRI-8M PCI: ************* XLOG recovery (877) *************
Aug 19 00:01:30 pbx divas: 150:21:04.143 F 2 Microcode:
Aug 19 00:01:30 pbx divas: 150:21:04.143 149:2510:241 - D-X(004) 00 01 01 59
Aug 19 00:01:30 pbx divas: 150:21:04.143 149:2510:246 - D-R(004) 02 01 01 D7

...

Aug 19 00:01:30 pbx divas: 150:21:04.152 150:1229:360 - D-R(004) 00 01 01 D7
Aug 19 00:01:30 pbx divas: 150:21:04.152 F 2 Diva Server 4BRI-8M PCI: ***************** end of XLOG *****************
Aug 19 00:01:30 pbx 'divas: debug usermode helper' +----------------------------- ADAPTER DUMP END   -----------------------+

Ein Call von heute früh sieht dann im Asterisk-Log wie folgt aus:

Aug 19 08:53:28 VERBOSE[20999] logger.c:     -- Executing Dial("Zap/2-1", "CAPI/g1/<NUMMER>/b||gTW") in new stack
Aug 19 08:53:28 VERBOSE[20999] logger.c:        > data = g1/<NUMMER>/b format=8
Aug 19 08:53:28 VERBOSE[20999] logger.c:        > parsed dialstring: 'g1' 'NULL' '<NUMMER>' 'b'
Aug 19 08:53:28 VERBOSE[20999] logger.c:        > capi request group = 2
Aug 19 08:53:28 VERBOSE[20999] logger.c:   == 4BRI-2#02: setting format alaw - 0x8 (alaw)
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-execute-dialout-s-1.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable MACRO_DEPTH.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable ARG2.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable ARG1.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable MACRO_PRIORITY.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable MACRO_CONTEXT.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable MACRO_EXTEN.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-out-international-<NUMMER>-1.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-from-internal-0<NUMMER>-2.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-19.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable theDialString.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-18.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-17.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-16.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-15.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-19.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-18.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable theCallerID.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-17.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-13.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-10.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-9.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-8.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable DB_RESULT.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-7.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-6.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-3.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-callerid-out-s-1.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-14.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable theAccess.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-13.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-11.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-10.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-9.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable MONITOR_FILENAME.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-6.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable theNumber.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-5.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable thePrefix.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-4.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-3.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable theTrunk.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-2.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-macro-prepare-dialout-s-1.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable STACK-from-internal-0<NUMMER>-1.
Aug 19 08:53:28 DEBUG[20999] channel.c: Not copying variable TRANSFERCAPABILITY.
Aug 19 08:53:28 VERBOSE[20999] logger.c:        > parsed dialstring: 'g1' 'NULL' '<NUMMER>' 'b'
Aug 19 08:53:28 VERBOSE[20999] logger.c:        > capi: peerlink -1 allocated, peer is unlinked
Aug 19 08:53:28 VERBOSE[20999] logger.c:   == 4BRI-2#02: Call CAPI/4BRI-2#02/<NUMMER>-e7 with B3  (pres=0x00, ton=0x00)
Aug 19 08:53:28 VERBOSE[20999] logger.c: CONNECT_REQ                ID=002 #0x343e LEN=0068
Aug 19 08:53:28 VERBOSE[20999] logger.c:     -- Called g1/<NUMMER>/b
Aug 19 08:53:28 DEBUG[20999] channel.c: Set channel CAPI/4BRI-2#02/<NUMMER>-e7 to read format slin
Aug 19 08:53:28 DEBUG[20999] channel.c: Set channel Zap/2-1 to write format slin
Aug 19 08:53:28 DEBUG[20999] channel.c: Set channel Zap/2-1 to read format slin
Aug 19 08:53:28 DEBUG[20999] channel.c: Set channel CAPI/4BRI-2#02/<NUMMER>-e7 to write format slin
Aug 19 08:53:28 VERBOSE[20999] logger.c:     -- CAPI/4BRI-2#02/<NUMMER>-e7 is busy
Aug 19 08:53:28 DEBUG[20999] channel.c: Hanging up channel 'CAPI/4BRI-2#02/<NUMMER>-e7'
Aug 19 08:53:28 VERBOSE[20999] logger.c:   == 4BRI-2#02: CAPI Hangingup for PLCI=0 in state 4
Aug 19 08:53:28 VERBOSE[20999] logger.c:   == 4BRI-2#02: Interface cleanup PLCI=0
Aug 19 08:53:28 VERBOSE[20999] logger.c:   == Everyone is busy/congested at this time (1:1/0/0)
Aug 19 08:53:28 DEBUG[20999] app_dial.c: Exiting with DIALSTATUS=BUSY.
Aug 19 08:53:28 DEBUG[20999] app_macro.c: Executed application: Dial

Vielleicht hilft das ja, damit mir jemand sagen kann, wo der Fehler zu suchen ist.

Noch als Ergänzung:
Debian GNU/Linux 4.0,
Kernel 2.6.18 (aus Sourcen),
Diva4Linux_installer_8.5-108-80.bin

 

[armincm]

Mit diesem Fehler 'trapped' und da du auch das Dialogic Treiber-Paket verwendest, solltest du Kontakt zu Dialogic aufnehmen.

Armin