Our company’s Asterisk PBX system with a Digium B410P card has been working wonderfully (and without change) since May 2007.
About a month ago, one of our two BRI ISDN lines started with intermittent faults, where – sometimes – when somebody phones into the system, they can hear us, but we can’t hear them. This happens about 60% of the time. The other line works just fine. The fault cannot be reliably duplicated and occurs seemingly random.
What I have done thus far is:
ul Phoned our service provider (Telkom SA) and logged a fault – RESULT: they tested the line and said that everything is just fine and the fault is with our equipment
(2) Swapped the Telkom Network Terminating devices between the two lines – RESULT: same problem
(3) Change ports on the card - RESULT: same problem
(4) Bought a new card – RESULT: same problem
(5) Busy setting up a new system with latest software – RESULT: an assortment of problems with incompatibilities between the new mISDN 1.2, the latest 1.1.7.2 and the latest kernel (>2.6.23.17). Currently ignoring this route and focusing on making the existing system work again.[/ul]
I have noticed a couple of things from the /var/log/asterisk/misdn.log file that could be an indication of a problem. Any help and comments would be GREATLY appreciated.
The BIG question is: Is the fault in our equipment, or is this a service provider fault?
The following 2 line from two different call logs in the misdn.log, right after a call has been detected incoming:
--> addr:0 l3id:4000a b_stid:0 layer_id:0 (NOT WORKING)
--> addr:0 l3id:4000b b_stid:0 layer_id:50010480 (WORKED)
The layer_id = 0 in the log where the caller could not be heard by us. What is the layer_id an indication of?
Then right before the call is answered by Asterisk, this first status line was present in the log of the call that did work, and absent in the call that went wrong:
[code]MGMT: SSTATUS: L2_ESTABLISH
- ANSWER:[/code]
Now the strange part: I have one logfile, of a call on our other incoming line – which always works – where the layer_id is also zero, and the L2_ESTABLISH is also missing… but the call worked?!?
Please help.
Thanks
Corne.
SETUP
Location: Pretoria, South Africa
Service Provider: Telkom SA
Slackware Linux with kernel 2.6.21.1 on an Intel Celeron 1.7G
Asterisk 1.4.4
mISDN 1.1.3
mISDNuser 1.1.3
zaptel 1.4.2.1
Digium b410p 4-port ISDN BRI card (port 3 & 4 in use)
/etc/misdn-init.conf
card=1,0x4,dtmf
nt_ptmp=1,2
te_ptmp=3,4
poll=128
dsp_poll=128
dsp_options=0
dtmfthreshold=50
debug=0
/etc/asterisk/misdn.conf
[general]
misdn_init=/etc/misdn-init.conf
debug=4
tracefile=/var/log/asterisk/misdn.log
ntdebugflags=0
ntdebugfile=/var/log/misdn-nt.log
bridging=no
stop_tone_after_first_digit=yes
append_digits2exten=yes
dynamic_crypt=no
crypt_prefix=**
crypt_keys=test,muh
[channels]
language=en
musicclass=default
senddtmf=yes
far_alerting=no
allowed_bearers=all
nationalprefix=
internationalprefix=
rxgain=0
txgain=0
te_choose_channel=no
pmp_l1_check=yes
reject_cause=16
need_more_infos=no
nttimeout=no
method=standard
dialplan=0
localdialplan=0
cpndialplan=0
early_bconnect=yes
incoming_early_audio=no
nodialtone=no
hold_allowed=yes
callgroup=1
pickupgroup=1
presentation=2
screen=1
echocancel=256
jitterbuffer=4000
jitterbuffer_upper_threshold=0
hdlc=yes
max_incoming=-1
max_outgoing=-1
always_immediate=yes
immediate=no
context=incoming
extensions.conf
msns=*
ports=3
msns=*
ports=4
NOT WORKING CALL LOG:
Sun Jun 8 09:37:27 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:3f082
Sun Jun 8 09:37:27 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:30582
Sun Jun 8 09:37:27 2008: P[ 4] set_channel: bc->channel:0 channel:1
Sun Jun 8 09:37:27 2008: P[ 4] I IND :NEW_CHANNEL oad: dad:1981 pid:2 state:none
Sun Jun 8 09:37:27 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 09:37:27 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 09:37:27 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 09:37:27 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 09:37:27 2008: P[ 4] --> addr:0 l3id:40003 b_stid:0 layer_id:0
Sun Jun 8 09:37:27 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:37:27 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 09:37:27 2008: P[ 4] Chan not existing at the moment bc->l3id:40003 bc:0x81ae2e0 event:NEW_CHANNEL port:4 channel:1
Sun Jun 8 09:37:27 2008: P[ 4] NO USERUESRINFO
Sun Jun 8 09:37:27 2008: P[ 4] set_chan_in_stack: 1
Sun Jun 8 09:37:27 2008: P[ 4] I IND :SETUP oad: dad:1981 pid:2 state:none
Sun Jun 8 09:37:27 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 09:37:27 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 09:37:27 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 09:37:27 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 09:37:27 2008: P[ 4] --> addr:0 l3id:40003 b_stid:0 layer_id:0
Sun Jun 8 09:37:27 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:37:27 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 09:37:27 2008: P[ 4] --> Bearer: Speech
Sun Jun 8 09:37:27 2008: P[ 4] --> Codec: Alaw
Sun Jun 8 09:37:27 2008: P[ 0] --> * NEW CHANNEL dad:1981 oad:
Sun Jun 8 09:37:27 2008: P[ 4] read_config: Getting Config
Sun Jun 8 09:37:27 2008: P[ 4] --> CTON: Unknown
Sun Jun 8 09:37:27 2008: P[ 4] --> EXPORT_PID: pid:2
Sun Jun 8 09:37:27 2008: P[ 4] --> PRES: Restricted (1)
Sun Jun 8 09:37:27 2008: P[ 4] --> SCREEN: Unscreened (0)
Sun Jun 8 09:37:27 2008: P[ 4] * Queuing chan 0x81fc8f8
Sun Jun 8 09:37:27 2008: P[ 4] I SEND:PROCEEDING oad: dad:1981 pid:2
Sun Jun 8 09:37:27 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 09:37:27 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 09:37:27 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 09:37:27 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 09:37:27 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 09:37:27 2008: P[ 4] --> addr:0 l3id:40003 b_stid:0 layer_id:0
Sun Jun 8 09:37:27 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:37:27 2008: P[ 4] --> incoming_early_audio off
Sun Jun 8 09:37:27 2008: P[ 4] * Starting Ast ctx:incoming dad:1981 oad: with ‘s’ extension
Sun Jun 8 09:37:27 2008: P[ 4] GOT SETUP OK
Sun Jun 8 09:37:27 2008: P[ 4] Sending msg, prim:30280 addr:41000404 dinfo:40003
Sun Jun 8 09:37:27 2008: P[ 4] * IND : ringing pid:2
Sun Jun 8 09:37:27 2008: P[ 4] --> * IND : ringing pid:2
Sun Jun 8 09:37:27 2008: P[ 4] I SEND:ALERTING oad: dad:1981 pid:2
Sun Jun 8 09:37:27 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 09:37:27 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 09:37:27 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 09:37:27 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 09:37:27 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 09:37:27 2008: P[ 4] --> addr:0 l3id:40003 b_stid:0 layer_id:0
Sun Jun 8 09:37:27 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:37:27 2008: P[ 4] --> * SEND: State Ring pid:2
Sun Jun 8 09:37:27 2008: P[ 4] --> incoming_early_audio off
Sun Jun 8 09:37:27 2008: P[ 4] Sending msg, prim:30180 addr:41000404 dinfo:40003
Sun Jun 8 09:37:31 2008: P[ 4] * ANSWER:
Sun Jun 8 09:37:31 2008: P[ 4] --> Connection is without BF encryption
Sun Jun 8 09:37:31 2008: P[ 4] --> None
Sun Jun 8 09:37:31 2008: P[ 4] --> empty cad using dad
Sun Jun 8 09:37:31 2008: P[ 4] I SEND:CONNECT oad: dad:1981 pid:2
Sun Jun 8 09:37:31 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 09:37:31 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:1981
Sun Jun 8 09:37:31 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 09:37:31 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 09:37:31 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 09:37:31 2008: P[ 4] --> addr:0 l3id:40003 b_stid:0 layer_id:0
Sun Jun 8 09:37:31 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:37:31 2008: P[ 4] setup_bc: with dsp
Sun Jun 8 09:37:31 2008: P[ 4] --> Channel is 1
Sun Jun 8 09:37:31 2008: P[ 4] --> TRANSPARENT Mode
Sun Jun 8 09:37:31 2008: P[ 4] ph_control: c1:2100 c2:0
Sun Jun 8 09:37:31 2008: P[ 4] ec_enable
Sun Jun 8 09:37:31 2008: P[ 4] Sending Control ECHOCAN_ON taps:256
Sun Jun 8 09:37:31 2008: P[ 4] Taps is 256
Sun Jun 8 09:37:31 2008: P[ 4] BCHAN: bchan ACT Confirm pid:2
Sun Jun 8 09:37:31 2008: P[ 4] Sending msg, prim:30780 addr:41000404 dinfo:40003
Sun Jun 8 09:37:32 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:30f82
Sun Jun 8 09:37:32 2008: P[ 4] I IND :CONNECT_ACKNOWLEDGE oad: dad:1981 pid:2 state:CONNECTED
Sun Jun 8 09:37:32 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:1981
Sun Jun 8 09:37:32 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 09:37:32 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 09:37:32 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 09:37:32 2008: P[ 4] --> addr:50010402 l3id:40003 b_stid:10010400 layer_id:50010480
Sun Jun 8 09:37:32 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:37:32 2008: P[ 4] --> bc_state:BCHAN_ACTIVATED
Sun Jun 8 09:37:47 2008: P[ 4] * IND : ringing pid:2
Sun Jun 8 09:37:47 2008: P[ 4] --> * IND : ringing pid:2 but Connected, so just send TONE_ALERTING without state changes
Sun Jun 8 09:37:47 2008: P[ 4] --> * UNHOLD pid:2
Sun Jun 8 09:37:47 2008: P[ 4] --> * IND : -1! (stop indication) pid:2
Sun Jun 8 09:37:47 2008: P[ 4] --> None
Sun Jun 8 09:38:00 2008: P[ 4] * IND : HANGUP pid:2 ctx:incoming dad:s oad: State:CONNECTED
Sun Jun 8 09:38:00 2008: P[ 4] --> l3id:40003
Sun Jun 8 09:38:00 2008: P[ 4] --> cause:16
Sun Jun 8 09:38:00 2008: P[ 4] --> out_cause:16
Sun Jun 8 09:38:00 2008: P[ 4] --> state:CONNECTED
Sun Jun 8 09:38:00 2008: P[ 4] I SEND:DISCONNECT oad: dad:1981 pid:2
Sun Jun 8 09:38:00 2008: P[ 4] --> bc_state:BCHAN_ACTIVATED
Sun Jun 8 09:38:00 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:1981
Sun Jun 8 09:38:00 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 09:38:00 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 09:38:00 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 09:38:00 2008: P[ 4] --> addr:50010402 l3id:40003 b_stid:10010400 layer_id:50010480
Sun Jun 8 09:38:00 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:38:00 2008: P[ 4] --> Channel: mISDN/3-u0 hanguped new state:CLEANING
Sun Jun 8 09:38:00 2008: P[ 4] Sending msg, prim:34580 addr:41000404 dinfo:40003
Sun Jun 8 09:38:00 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:34d82
Sun Jun 8 09:38:00 2008: P[ 4] empty_chan_in_stack: 1
Sun Jun 8 09:38:00 2008: P[ 4] $$$ CLEANUP CALLED pid:2
Sun Jun 8 09:38:00 2008: P[ 4] $$$ Cleaning up bc with stid :10010400 pid:2
Sun Jun 8 09:38:00 2008: P[ 4] --> ec_disable
Sun Jun 8 09:38:00 2008: P[ 4] Sending Control ECHOCAN_OFF
Sun Jun 8 09:38:00 2008: P[ 4] ph_control: c1:2319 c2:0
Sun Jun 8 09:38:00 2008: P[ 4] I IND :RELEASE oad: dad: pid:2 state:CLEANING
Sun Jun 8 09:38:00 2008: P[ 4] --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 09:38:00 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
Sun Jun 8 09:38:00 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:0
Sun Jun 8 09:38:00 2008: P[ 4] --> screen:0 --> pres:0
Sun Jun 8 09:38:00 2008: P[ 4] --> addr:50010402 l3id:40003 b_stid:0 layer_id:50010480
Sun Jun 8 09:38:00 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:38:00 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 09:38:00 2008: P[ 4] ast_hangup already called, so we have no ast ptr anymore in event(RELEASE)
Sun Jun 8 09:38:00 2008: P[ 4] --> No need to queue hangup
Sun Jun 8 09:38:00 2008: P[ 4] Cannot hangup chan, no ast
Sun Jun 8 09:38:00 2008: P[ 4] I SEND:RELEASE_COMPLETE oad: dad: pid:2
Sun Jun 8 09:38:00 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 09:38:00 2008: P[ 4] --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 09:38:00 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
Sun Jun 8 09:38:00 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:0
Sun Jun 8 09:38:00 2008: P[ 4] --> screen:0 --> pres:0
Sun Jun 8 09:38:00 2008: P[ 4] --> addr:50010402 l3id:40003 b_stid:0 layer_id:50010480
Sun Jun 8 09:38:00 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 09:38:00 2008: P[ 4] $$$ CLEANUP CALLED pid:2
Sun Jun 8 09:38:00 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:3f182
Sun Jun 8 09:38:00 2008: P[ 4] --> lib: RELEASE_CR Ind with l3id:40003
Sun Jun 8 09:38:00 2008: P[ 4] --> lib: CLEANING UP l3id: 40003
Sun Jun 8 09:38:00 2008: P[ 4] $$$ CLEANUP CALLED pid:2
Sun Jun 8 09:38:00 2008: P[ 4] BCHAN: MGR_DELLAYER|CNF pid:2
Sun Jun 8 09:38:00 2008: P[ 4] Sending msg, prim:35a80 addr:41000404 dinfo:40003
Sun Jun 8 09:38:02 2008: P[ 4] MGMT: SSTATUS: L2_RELEASED
WORKING CALL LOG
Sun Jun 8 10:25:27 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:3f082
Sun Jun 8 10:25:27 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:30582
Sun Jun 8 10:25:27 2008: P[ 4] set_channel: bc->channel:0 channel:1
Sun Jun 8 10:25:27 2008: P[ 4] I IND :NEW_CHANNEL oad: dad:1981 pid:3 state:none
Sun Jun 8 10:25:27 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 10:25:27 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 10:25:27 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 10:25:27 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 10:25:27 2008: P[ 4] --> addr:0 l3id:4000b b_stid:0 layer_id:50010480
Sun Jun 8 10:25:27 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:25:27 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 10:25:27 2008: P[ 4] Chan not existing at the moment bc->l3id:4000b bc:0x81ae2e0 event:NEW_CHANNEL port:4 channel:1
Sun Jun 8 10:25:27 2008: P[ 4] NO USERUESRINFO
Sun Jun 8 10:25:27 2008: P[ 4] set_chan_in_stack: 1
Sun Jun 8 10:25:27 2008: P[ 4] I IND :SETUP oad: dad:1981 pid:3 state:none
Sun Jun 8 10:25:27 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 10:25:27 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 10:25:27 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 10:25:27 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 10:25:27 2008: P[ 4] --> addr:0 l3id:4000b b_stid:0 layer_id:50010480
Sun Jun 8 10:25:27 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:25:27 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 10:25:27 2008: P[ 4] --> Bearer: Speech
Sun Jun 8 10:25:27 2008: P[ 4] --> Codec: Alaw
Sun Jun 8 10:25:27 2008: P[ 0] --> * NEW CHANNEL dad:1981 oad:
Sun Jun 8 10:25:27 2008: P[ 4] read_config: Getting Config
Sun Jun 8 10:25:27 2008: P[ 4] --> CTON: Unknown
Sun Jun 8 10:25:27 2008: P[ 4] --> EXPORT_PID: pid:3
Sun Jun 8 10:25:27 2008: P[ 4] --> PRES: Restricted (1)
Sun Jun 8 10:25:27 2008: P[ 4] --> SCREEN: Unscreened (0)
Sun Jun 8 10:25:27 2008: P[ 4] * Queuing chan 0x81fc0f0
Sun Jun 8 10:25:27 2008: P[ 4] I SEND:PROCEEDING oad: dad:1981 pid:3
Sun Jun 8 10:25:27 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 10:25:27 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 10:25:27 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 10:25:27 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 10:25:27 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 10:25:27 2008: P[ 4] --> addr:0 l3id:4000b b_stid:0 layer_id:50010480
Sun Jun 8 10:25:27 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:25:27 2008: P[ 4] --> incoming_early_audio off
Sun Jun 8 10:25:27 2008: P[ 4] * Starting Ast ctx:incoming dad:1981 oad: with ‘s’ extension
Sun Jun 8 10:25:27 2008: P[ 4] GOT SETUP OK
Sun Jun 8 10:25:27 2008: P[ 4] Sending msg, prim:30280 addr:41000404 dinfo:4000b
Sun Jun 8 10:25:27 2008: P[ 4] * IND : ringing pid:3
Sun Jun 8 10:25:27 2008: P[ 4] --> * IND : ringing pid:3
Sun Jun 8 10:25:27 2008: P[ 4] I SEND:ALERTING oad: dad:1981 pid:3
Sun Jun 8 10:25:27 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 10:25:27 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 10:25:27 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 10:25:27 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 10:25:27 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 10:25:27 2008: P[ 4] --> addr:0 l3id:4000b b_stid:0 layer_id:50010480
Sun Jun 8 10:25:27 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:25:27 2008: P[ 4] Sending msg, prim:30180 addr:41000404 dinfo:4000b
Sun Jun 8 10:25:27 2008: P[ 4] --> * SEND: State Ring pid:3
Sun Jun 8 10:25:27 2008: P[ 4] --> incoming_early_audio off
Sun Jun 8 10:25:27 2008: P[ 4] MGMT: SSTATUS: L2_ESTABLISH
Sun Jun 8 10:25:31 2008: P[ 4] * ANSWER:
Sun Jun 8 10:25:31 2008: P[ 4] --> Connection is without BF encryption
Sun Jun 8 10:25:31 2008: P[ 4] --> None
Sun Jun 8 10:25:31 2008: P[ 4] --> empty cad using dad
Sun Jun 8 10:25:31 2008: P[ 4] I SEND:CONNECT oad: dad:1981 pid:3
Sun Jun 8 10:25:31 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 10:25:31 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:1981
Sun Jun 8 10:25:31 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 10:25:31 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 10:25:31 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 10:25:31 2008: P[ 4] --> addr:0 l3id:4000b b_stid:0 layer_id:50010480
Sun Jun 8 10:25:31 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:25:31 2008: P[ 4] setup_bc: with dsp
Sun Jun 8 10:25:31 2008: P[ 0] mISDN_read wants us to wait
Sun Jun 8 10:25:31 2008: P[ 4] --> Channel is 1
Sun Jun 8 10:25:31 2008: P[ 4] --> TRANSPARENT Mode
Sun Jun 8 10:25:31 2008: P[ 4] ph_control: c1:2100 c2:0
Sun Jun 8 10:25:31 2008: P[ 4] ec_enable
Sun Jun 8 10:25:31 2008: P[ 4] Sending Control ECHOCAN_ON taps:256
Sun Jun 8 10:25:31 2008: P[ 4] Taps is 256
Sun Jun 8 10:25:31 2008: P[ 4] Sending msg, prim:30780 addr:41000404 dinfo:4000b
Sun Jun 8 10:25:31 2008: P[ 4] BCHAN: bchan ACT Confirm pid:3
Sun Jun 8 10:25:32 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:30f82
Sun Jun 8 10:25:32 2008: P[ 4] I IND :CONNECT_ACKNOWLEDGE oad: dad:1981 pid:3 state:CONNECTED
Sun Jun 8 10:25:32 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:1981
Sun Jun 8 10:25:32 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 10:25:32 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 10:25:32 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 10:25:32 2008: P[ 4] --> addr:50010402 l3id:4000b b_stid:10010400 layer_id:50010480
Sun Jun 8 10:25:32 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:25:32 2008: P[ 4] --> bc_state:BCHAN_ACTIVATED
Sun Jun 8 10:25:47 2008: P[ 4] * IND : ringing pid:3
Sun Jun 8 10:25:47 2008: P[ 4] --> * IND : ringing pid:3 but Connected, so just send TONE_ALERTING without state changes
Sun Jun 8 10:25:52 2008: P[ 4] --> * UNHOLD pid:3
Sun Jun 8 10:25:52 2008: P[ 4] --> * IND : -1! (stop indication) pid:3
Sun Jun 8 10:25:52 2008: P[ 4] --> None
Sun Jun 8 10:26:00 2008: P[ 4] * IND : HANGUP pid:3 ctx:incoming dad:s oad: State:CONNECTED
Sun Jun 8 10:26:00 2008: P[ 4] --> l3id:4000b
Sun Jun 8 10:26:00 2008: P[ 4] --> cause:16
Sun Jun 8 10:26:00 2008: P[ 4] --> out_cause:16
Sun Jun 8 10:26:00 2008: P[ 4] --> state:CONNECTED
Sun Jun 8 10:26:00 2008: P[ 4] I SEND:DISCONNECT oad: dad:1981 pid:3
Sun Jun 8 10:26:00 2008: P[ 4] --> bc_state:BCHAN_ACTIVATED
Sun Jun 8 10:26:00 2008: P[ 4] --> channel:1 mode:TE cause:16 ocause:16 rad: cad:1981
Sun Jun 8 10:26:00 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan: cpnnumplan:0
Sun Jun 8 10:26:00 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:1
Sun Jun 8 10:26:00 2008: P[ 4] --> screen:0 --> pres:1
Sun Jun 8 10:26:00 2008: P[ 4] --> addr:50010402 l3id:4000b b_stid:10010400 layer_id:50010480
Sun Jun 8 10:26:00 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:26:00 2008: P[ 4] --> Channel: mISDN/3-u1 hanguped new state:CLEANING
Sun Jun 8 10:26:00 2008: P[ 4] Sending msg, prim:34580 addr:41000404 dinfo:4000b
Sun Jun 8 10:26:00 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:34d82
Sun Jun 8 10:26:00 2008: P[ 4] empty_chan_in_stack: 1
Sun Jun 8 10:26:00 2008: P[ 4] $$$ CLEANUP CALLED pid:3
Sun Jun 8 10:26:00 2008: P[ 4] $$$ Cleaning up bc with stid :10010400 pid:3
Sun Jun 8 10:26:00 2008: P[ 4] --> ec_disable
Sun Jun 8 10:26:00 2008: P[ 4] Sending Control ECHOCAN_OFF
Sun Jun 8 10:26:00 2008: P[ 4] ph_control: c1:2319 c2:0
Sun Jun 8 10:26:00 2008: P[ 4] I IND :RELEASE oad: dad: pid:3 state:CLEANING
Sun Jun 8 10:26:00 2008: P[ 4] --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 10:26:00 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
Sun Jun 8 10:26:00 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:0
Sun Jun 8 10:26:00 2008: P[ 4] --> screen:0 --> pres:0
Sun Jun 8 10:26:00 2008: P[ 4] --> addr:50010402 l3id:4000b b_stid:0 layer_id:50010480
Sun Jun 8 10:26:00 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:26:00 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 10:26:00 2008: P[ 4] ast_hangup already called, so we have no ast ptr anymore in event(RELEASE)
Sun Jun 8 10:26:00 2008: P[ 4] --> No need to queue hangup
Sun Jun 8 10:26:00 2008: P[ 4] Cannot hangup chan, no ast
Sun Jun 8 10:26:00 2008: P[ 4] I SEND:RELEASE_COMPLETE oad: dad: pid:3
Sun Jun 8 10:26:00 2008: P[ 4] --> bc_state:BCHAN_CLEANED
Sun Jun 8 10:26:00 2008: P[ 4] --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
Sun Jun 8 10:26:00 2008: P[ 4] --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
Sun Jun 8 10:26:00 2008: P[ 4] --> caps:Speech pi:0 keypad: sending_complete:0
Sun Jun 8 10:26:00 2008: P[ 4] --> screen:0 --> pres:0
Sun Jun 8 10:26:00 2008: P[ 4] --> addr:50010402 l3id:4000b b_stid:0 layer_id:50010480
Sun Jun 8 10:26:00 2008: P[ 4] --> facility:Fac_None out_facility:Fac_None
Sun Jun 8 10:26:00 2008: P[ 4] $$$ CLEANUP CALLED pid:3
Sun Jun 8 10:26:00 2008: P[ 4] handle_frm: frm->addr:42000403 frm->prim:3f182
Sun Jun 8 10:26:00 2008: P[ 4] --> lib: RELEASE_CR Ind with l3id:4000b
Sun Jun 8 10:26:00 2008: P[ 4] --> lib: CLEANING UP l3id: 4000b
Sun Jun 8 10:26:00 2008: P[ 4] $$$ CLEANUP CALLED pid:3
Sun Jun 8 10:26:00 2008: P[ 4] BCHAN: MGR_DELLAYER|CNF pid:3
Sun Jun 8 10:26:00 2008: P[ 4] Sending msg, prim:35a80 addr:41000404 dinfo:4000b
Sun Jun 8 10:26:02 2008: P[ 4] MGMT: SSTATUS: L2_RELEASED