[asterisk-users] b410p mIDSN - RNIS signaling problems

Olivier Fauchon olivier at aixmarseille.com
Wed Nov 5 15:20:34 CST 2008


Hi.

I'm running Asterisk server with 10 sip phones, and 2 grouped T0 lines 
with 10  DDI numbers.
My provider is France Telecom and my setup is :

- Debian Lenny
- Asterisk 1.4
- Linux kernel  2.6.25.17
- mISDN 1.1.8 driver
- Sip phones Thomson ST2030

No problem with the SIP .

But when reveiving a call on RNIS line (any of the DDI numbers),  the  
associated SIP phone rings indicating _two_ incoming calls !
Turning on misdn debuging seems to indicate there are _2 identical 
incoming calls_ on 2 ports at the same time (See the log below)

It' now many days I'm looking for an answer, I really need help !

Thx

 * /etc/asterisk/misdn.conf

[general]
debug=0
method=standard
append_digits2exten=yes
bridging=yes
bridging=no
language=fr
echocancel=yes
echotraining=yes
jitterbuffer=4000
jitterbuffer_upper_threshold=0
use_callingpres=yes
presentation=allowed
[default]
context=numeris
language=fr
nationalprefix=0
internationalprefix=00
rxgain=0
txgain=0
;dialplan=0
use_callingpres=yes
presentation=allowed
senddtmf=yes
[numeris]
context=numeris-in
ports=1,2,3,4
msns=*


  * /etc/misdn-init.conf

card=1,0x4
te_ptmp=1,2,3,4
poll=128
dsp_poll=128
dsp_options=0
dtmfthreshold=100
debug=0
obelix:/etc/as


  * SIP configuration
[default]
exten => 412,1,Dial(SIP/hard_sysadmins&SIP/ofauchon_soft,30)
exten => 412,2,Voicemail(412)
[numeris-in]
exten =>  0412,1,Goto(default,412,1)



  * Log of an incoming call  (notice the activity on both ports)

Wed Nov  5 21:04:12 2008: P[ 0]  Got empty Msg..
Wed Nov  5 21:04:15 2008: P[ 0]  MGMT: Short status dinfo 1000001
Wed Nov  5 21:04:15 2008: P[ 0]  MGMT: SSTATUS: L1_ACTIVATED
Wed Nov  5 21:04:15 2008: P[ 0]  MGMT: Short status dinfo 1000001
Wed Nov  5 21:04:15 2008: P[ 0]  MGMT: SSTATUS: L1_ACTIVATED
Wed Nov  5 21:04:15 2008: P[ 2]  handle_frm: frm->addr:42000203 
frm->prim:3f082
Wed Nov  5 21:04:15 2008: P[ 2]   --> lib: NEW_CR Ind with l3id:4004e on 
this port.
Wed Nov  5 21:04:15 2008: P[ 2]  channel with stid:0 for one second 
still in use!
Wed Nov  5 21:04:15 2008: P[ 2]   --> new_process: New L3Id: 4004e
Wed Nov  5 21:04:15 2008: P[ 2]  handle_frm: frm->addr:42000203 
frm->prim:30582
Wed Nov  5 21:04:15 2008: P[ 2]  set_channel: bc->channel:0 channel:1
Wed Nov  5 21:04:15 2008: P[ 2]  $$$ find_chan: No channel found for 
oad:610493763 dad:0412
Wed Nov  5 21:04:15 2008: P[ 0]  get_index: event not found!
Wed Nov  5 21:04:15 2008: P[ 2]  I IND :NEW_CHANNEL oad:610493763 
dad:0412 pid:74 state:none
Wed Nov  5 21:04:15 2008: P[ 2]   --> channel:1 mode:TE cause:16 
ocause:16 rad: cad:
Wed Nov  5 21:04:15 2008: P[ 2]   --> info_dad: onumplan:2 dnumplan:0 
rnumplan:  cpnnumplan:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> caps:Speech pi:0 keypad: 
sending_complete:1
Wed Nov  5 21:04:15 2008: P[ 2]   --> screen:0 --> pres:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> addr:0 l3id:4004e b_stid:0 
layer_id:50010280
Wed Nov  5 21:04:15 2008: P[ 2]   --> facility:Fac_None 
out_facility:Fac_None
Wed Nov  5 21:04:15 2008: P[ 2]   --> urate:0 rate:16 mode:0 user1:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> bc:4352e1c h:0 sh:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> bc_state:BCHAN_CLEANED
Wed Nov  5 21:04:15 2008: P[ 0]  get_index: event not found!
Wed Nov  5 21:04:15 2008: P[ 2]  Chan not existing at the moment 
bc->l3id:4004e bc:0x4352e1c event:NEW_CHANNEL port:2 channel:1
Wed Nov  5 21:04:15 2008: P[ 2]  NO USERUESRINFO
Wed Nov  5 21:04:15 2008: P[ 2]  find_free_chan: req_chan:1
Wed Nov  5 21:04:15 2008: P[ 2]   --> found chan (preselected): 1
Wed Nov  5 21:04:15 2008: P[ 2]  set_chan_in_stack: 1
Wed Nov  5 21:04:15 2008: P[ 2]  Idx:0 stack->cchan:0 in_use:1 Chan:1
Wed Nov  5 21:04:15 2008: P[ 2]  Idx:1 stack->cchan:0 in_use:0 Chan:2
Wed Nov  5 21:04:15 2008: P[ 2]  Idx:2 stack->cchan:0 in_use:0 Chan:3
Wed Nov  5 21:04:15 2008: P[ 2]  $$$ Setting up bc with stid :10010200
Wed Nov  5 21:04:15 2008: P[ 2]  setup_bc: with dsp
Wed Nov  5 21:04:15 2008: P[ 2]   --> Channel is 1
Wed Nov  5 21:04:15 2008: P[ 2]   --> TRANSPARENT Mode
Wed Nov  5 21:04:15 2008: P[ 2]  $$$ Bchan Activated addr 50010202
Wed Nov  5 21:04:15 2008: P[ 2]  BC_STATE_CHANGE: l3id:4004e 
from:BCHAN_CLEANED to:BCHAN_ACTIVATED
Wed Nov  5 21:04:15 2008: P[ 2]  lib Got Prim: Addr 42000203 prim 30582 
dinfo 4004e
Wed Nov  5 21:04:15 2008: P[ 2]  $$$ find_chan: No channel found for 
oad:610493763 dad:0412
Wed Nov  5 21:04:15 2008: P[ 2]  I IND :SETUP oad:610493763 dad:0412 
pid:74 state:none
Wed Nov  5 21:04:15 2008: P[ 2]   --> channel:1 mode:TE cause:16 
ocause:16 rad: cad:
Wed Nov  5 21:04:15 2008: P[ 2]   --> info_dad: onumplan:2 dnumplan:0 
rnumplan:  cpnnumplan:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> caps:Speech pi:0 keypad: 
sending_complete:1
Wed Nov  5 21:04:15 2008: P[ 2]   --> screen:0 --> pres:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> addr:50010202 l3id:4004e 
b_stid:10010200 layer_id:50010280
Wed Nov  5 21:04:15 2008: P[ 2]   --> facility:Fac_None 
out_facility:Fac_None
 Wed Nov  5 21:04:15 2008: P[ 2]   --> urate:0 rate:16 mode:0 user1:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> bc:4352e1c h:0 sh:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> bc_state:BCHAN_ACTIVATED
Wed Nov  5 21:04:15 2008: P[ 2]  $$$ find_chan: No channel found for 
oad:610493763 dad:0412
Wed Nov  5 21:04:15 2008: P[ 2]   --> Bearer: Speech
Wed Nov  5 21:04:15 2008: P[ 2]   --> Codec: Alaw
Wed Nov  5 21:04:15 2008: P[ 2]   --> Bearer: Speech
Wed Nov  5 21:04:15 2008: P[ 2]   --> Codec: Alaw
Wed Nov  5 21:04:15 2008: P[ 0]   --> * NEW CHANNEL dad:0412 oad:610493763
Wed Nov  5 21:04:15 2008: P[ 2]  read_config: Getting Config
Wed Nov  5 21:04:15 2008: P[ 2]  config_jb: Called
Wed Nov  5 21:04:15 2008: P[ 2]   --> * CallGrp: PickupGrp:
Wed Nov  5 21:04:15 2008: P[ 2]   --> CTON: Unknown
Wed Nov  5 21:04:15 2008: P[ 2]   --> EXPORT_PID: pid:74
Wed Nov  5 21:04:15 2008: P[ 2]   --> PRES: Restricted (0)
Wed Nov  5 21:04:15 2008: P[ 2]   --> SCREEN: Unscreened (0)
Wed Nov  5 21:04:15 2008: P[ 2]  * Queuing chan 0x9121c28
Wed Nov  5 21:04:15 2008: P[ 2]  CONTEXT:numeris-in
Wed Nov  5 21:04:15 2008: P[ 2]  SENDEVENT: stack->nt:0 
stack->uperid:40000204
Wed Nov  5 21:04:15 2008: P[ 2]  I SEND:PROCEEDING oad:0610493763 
dad:0412 pid:74
Wed Nov  5 21:04:15 2008: P[ 2]   --> bc_state:BCHAN_ACTIVATED
Wed Nov  5 21:04:15 2008: P[ 2]   --> channel:1 mode:TE cause:16 
ocause:16 rad: cad:
Wed Nov  5 21:04:15 2008: P[ 2]   --> info_dad: onumplan:2 dnumplan:0 
rnumplan:  cpnnumplan:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> caps:Speech pi:0 keypad: 
sending_complete:1
Wed Nov  5 21:04:15 2008: P[ 2]   --> screen:0 --> pres:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> addr:50010202 l3id:4004e 
b_stid:10010200 layer_id:50010280
Wed Nov  5 21:04:15 2008: P[ 2]   --> facility:Fac_None 
out_facility:Fac_None
Wed Nov  5 21:04:15 2008: P[ 2]   --> urate:0 rate:16 mode:0 user1:0
Wed Nov  5 21:04:15 2008: P[ 2]   --> bc:4352e1c h:0 sh:0
Wed Nov  5 21:04:15 2008: P[ 2]  Sending msg, prim:30280 addr:41000204 
dinfo:4004e
Wed Nov  5 21:04:15 2008: P[ 2]  GOT SETUP OK
Wed Nov  5 21:04:15 2008: P[ 2]  Freeing Msg on prim:30582
Wed Nov  5 21:04:15 2008: P[ 1]  handle_frm: frm->addr:42000103 
frm->prim:3f082
Wed Nov  5 21:04:15 2008: P[ 1]   --> lib: NEW_CR Ind with l3id:20052 on 
this port.
Wed Nov  5 21:04:15 2008: P[ 1]  channel with stid:0 for one second 
still in use!
Wed Nov  5 21:04:16 2008: P[ 1]   --> new_process: New L3Id: 20052
Wed Nov  5 21:04:16 2008: P[ 1]  handle_frm: frm->addr:42000103 
frm->prim:30582
Wed Nov  5 21:04:16 2008: P[ 1]  set_channel: bc->channel:0 channel:1
Wed Nov  5 21:04:16 2008: P[ 1]  $$$ find_chan: No channel found for 
oad:610493763 dad:0412
Wed Nov  5 21:04:16 2008: P[ 0]  get_index: event not found!
Wed Nov  5 21:04:16 2008: P[ 1]  I IND :NEW_CHANNEL oad:610493763 
dad:0412 pid:75 state:none
Wed Nov  5 21:04:16 2008: P[ 1]   --> channel:1 mode:TE cause:16 
ocause:16 rad: cad:
Wed Nov  5 21:04:16 2008: P[ 2]  * IND : Indication [3] from 412
Wed Nov  5 21:04:16 2008: P[ 2]  * IND :        ringing pid:74
Wed Nov  5 21:04:16 2008: P[ 1]   --> info_dad: onumplan:2 dnumplan:0 
rnumplan:  cpnnumplan:0
Wed Nov  5 21:04:16 2008: P[ 2]   --> * IND :   ringing pid:74
 Wed Nov  5 21:04:16 2008: P[ 1]   --> caps:Speech pi:0 keypad: 
sending_complete:1
Wed Nov  5 21:04:16 2008: P[ 1]   --> screen:0 --> pres:0
Wed Nov  5 21:04:16 2008: P[ 2]  SENDEVENT: stack->nt:0 
stack->uperid:40000204
Wed Nov  5 21:04:16 2008: P[ 2]  I SEND:ALERTING oad:0610493763 dad:0412 
pid:74
Wed Nov  5 21:04:16 2008: P[ 1]   --> addr:0 l3id:20052 b_stid:0 
layer_id:50010180
Wed Nov  5 21:04:16 2008: P[ 2]   --> bc_state:BCHAN_ACTIVATED
Wed Nov  5 21:04:16 2008: P[ 1]   --> facility:Fac_None 
out_facility:Fac_None
Wed Nov  5 21:04:16 2008: P[ 2]   --> channel:1 mode:TE cause:16 
ocause:16 rad: cad:
Wed Nov  5 21:04:16 2008: P[ 1]   --> urate:0 rate:16 mode:0 user1:0
Wed Nov  5 21:04:16 2008: P[ 2]   --> info_dad: onumplan:2 dnumplan:0 
rnumplan:  cpnnumplan:0
Wed Nov  5 21:04:16 2008: P[ 1]   --> bc:434680c h:0 sh:0
Wed Nov  5 21:04:16 2008: P[ 2]   --> caps:Speech pi:0 keypad: 
sending_complete:1
Wed Nov  5 21:04:16 2008: P[ 1]   --> bc_state:BCHAN_CLEANED
Wed Nov  5 21:04:16 2008: P[ 2]   --> screen:0 --> pres:0
Wed Nov  5 21:04:16 2008: P[ 0]  get_index: event not found!
Wed Nov  5 21:04:16 2008: P[ 2]   --> addr:50010202 l3id:4004e 
b_stid:10010200 layer_id:50010280
Wed Nov  5 21:04:16 2008: P[ 1]  Chan not existing at the moment 
bc->l3id:20052 bc:0x434680c event:NEW_CHANNEL port:1 channel:1
Wed Nov  5 21:04:16 2008: P[ 2]   --> facility:Fac_None 
out_facility:Fac_None
Wed Nov  5 21:04:16 2008: P[ 1]  NO USERUESRINFO
Wed Nov  5 21:04:16 2008: P[ 2]   --> urate:0 rate:16 mode:0 user1:0
Wed Nov  5 21:04:16 2008: P[ 1]  find_free_chan: req_chan:1
Wed Nov  5 21:04:16 2008: P[ 2]   --> bc:4352e1c h:0 sh:0
Wed Nov  5 21:04:16 2008: P[ 2]  Sending msg, prim:30180 addr:41000204 
dinfo:4004e
Wed Nov  5 21:04:16 2008: P[ 1]   --> found chan (preselected): 1
Wed Nov  5 21:04:16 2008: P[ 1]  set_chan_in_stack: 1
Wed Nov  5 21:04:16 2008: P[ 2]   --> * SEND: State Ring pid:74
Wed Nov  5 21:04:16 2008: P[ 1]  Idx:0 stack->cchan:0 in_use:1 Chan:1
Wed Nov  5 21:04:16 2008: P[ 2]   --> incoming_early_audio off
Wed Nov  5 21:04:16 2008: P[ 1]  Idx:1 stack->cchan:0 in_use:0 Chan:2
Wed Nov  5 21:04:16 2008: P[ 1]  Idx:2 stack->cchan:0 in_use:0 Chan:3
Wed Nov  5 21:04:16 2008: P[ 1]  $$$ Setting up bc with stid :10010100
Wed Nov  5 21:04:16 2008: P[ 1]  setup_bc: with dsp
Wed Nov  5 21:04:16 2008: P[ 1]   --> Channel is 1
Wed Nov  5 21:04:16 2008: P[ 1]   --> TRANSPARENT Mode
Wed Nov  5 21:04:16 2008: P[ 1]  $$$ Bchan Activated addr 50010102
Wed Nov  5 21:04:16 2008: P[ 1]  BC_STATE_CHANGE: l3id:20052 
from:BCHAN_CLEANED to:BCHAN_ACTIVATED
Wed Nov  5 21:04:16 2008: P[ 1]  lib Got Prim: Addr 42000103 prim 30582 
dinfo 20052
Wed Nov  5 21:04:16 2008: P[ 1]  $$$ find_chan: No channel found for 
oad:610493763 dad:0412
Wed Nov  5 21:04:16 2008: P[ 1]  I IND :SETUP oad:610493763 dad:0412 
pid:75 state:none
Wed Nov  5 21:04:16 2008: P[ 1]   --> channel:1 mode:TE cause:16 
ocause:16 rad: cad:
Wed Nov  5 21:04:16 2008: P[ 1]   --> info_dad: onumplan:2 dnumplan:0 
rnumplan:  cpnnumplan:0
Wed Nov  5 21:04:16 2008: P[ 1]   --> caps:Speech pi:0 keypad: 
sending_complete:1
Wed Nov  5 21:04:16 2008: P[ 1]   --> screen:0 --> pres:0
Wed Nov  5 21:04:16 2008: P[ 1]   --> addr:50010102 l3id:20052 
b_stid:10010100 layer_id:50010180
Wed Nov  5 21:04:16 2008: P[ 1]   --> facility:Fac_None 
out_facility:Fac_None
Wed Nov  5 21:04:16 2008: P[ 1]   --> urate:0 rate:16 mode:0 user1:0
Wed Nov  5 21:04:16 2008: P[ 1]   --> bc:434680c h:0 sh:0
Wed Nov  5 21:04:16 2008: P[ 1]   --> bc_state:BCHAN_ACTIVATED
Wed Nov  5 21:04:16 2008: P[ 1]  $$$ find_chan: No channel found for 
oad:610493763 dad:0412
Wed Nov  5 21:04:16 2008: P[ 1]   --> Bearer: Speech
Wed Nov  5 21:04:16 2008: P[ 1]   --> Codec: Alaw
Wed Nov  5 21:04:16 2008: P[ 1]   --> Bearer: Speech
Wed Nov  5 21:04:16 2008: P[ 1]   --> Codec: Alaw
Wed Nov  5 21:04:16 2008: P[ 0]   --> * NEW CHANNEL dad:0412 oad:610493763
Wed Nov  5 21:04:16 2008: P[ 1]  read_config: Getting Config
Wed Nov  5 21:04:16 2008: P[ 1]  config_jb: Called
Wed Nov  5 21:04:16 2008: P[ 1]   --> * CallGrp: PickupGrp:
Wed Nov  5 21:04:16 2008: P[ 1]   --> CTON: Unknown
Wed Nov  5 21:04:16 2008: P[ 1]   --> EXPORT_PID: pid:75
Wed Nov  5 21:04:16 2008: P[ 1]   --> PRES: Restricted (0)
Wed Nov  5 21:04:16 2008: P[ 1]   --> SCREEN: Unscreened (0)
Wed Nov  5 21:04:16 2008: P[ 1]  * Queuing chan 0x4422258
Wed Nov  5 21:04:16 2008: P[ 1]  CONTEXT:numeris-in
Wed Nov  5 21:04:16 2008: P[ 1]  SENDEVENT: stack->nt:0 
stack->uperid:40000104
Wed Nov  5 21:04:16 2008: P[ 1]  I SEND:PROCEEDING oad:0610493763 
dad:0412 pid:75
Wed Nov  5 21:04:16 2008: P[ 1]   --> bc_state:BCHAN_ACTIVATED
Wed Nov  5 21:04:16 2008: P[ 1]   --> channel:1 mode:TE cause:16 
ocause:16 rad: cad:
Wed Nov  5 21:04:16 2008: P[ 1]   --> info_dad: onumplan:2 dnumplan:0 
rnumplan:  cpnnumplan:0
Wed Nov  5 21:04:16 2008: P[ 1]   --> caps:Speech pi:0 keypad: 
sending_complete:1
Wed Nov  5 21:04:16 2008: P[ 1]   --> screen:0 --> pres:0
Wed Nov  5 21:04:16 2008: P[ 1]   --> addr:50010102 l3id:20052 
b_stid:10010100 layer_id:50010180
Wed Nov  5 21:04:16 2008: P[ 1]   --> facility:Fac_None 
out_facility:Fac_None
Wed Nov  5 21:04:16 2008: P[ 1]   --> urate:0 rate:16 mode:0 user1:0
Wed Nov  5 21:04:16 2008: P[ 1]   --> bc:434680c h:0 sh:0
Wed Nov  5 21:04:16 2008: P[ 1]  Sending msg, prim:30280 addr:41000104 
dinfo:20052
Wed Nov  5 21:04:16 2008: P[ 1]  GOT SETUP OK
Wed Nov  5 21:04:16 2008: P[ 1]  Freeing Msg on prim:30582
Wed Nov  5 21:04:16 2008: P[ 2]  BCHAN: bchan ACT Confirm pid:74
Wed Nov  5 21:04:16 2008: P[ 0]  misdn_jb_empty: Wait...requested:48 
p:43d18b8
Wed Nov  5 21:04:16 2008: P[ 2]  Transmitting 48 samples 2 misdn
Wed Nov  5 21:04:16 2008: P[ 2]  writing 48 bytes 2 asterisk
Wed Nov  5 21:04:16 2008: P[ 0]  misdn_jb_empty: Wait...requested:128 
p:43d18b8
Wed Nov  5 21:04:16 2008: P[ 2]  Transmitting 128 samples 2 misdn
Wed Nov  5 21:04:16 2008: P[ 2]  writing 128 bytes 2 asterisk
Wed Nov  5 21:04:16 2008: P[ 0]  misdn_jb_empty: Wait...requested:128 
p:43d18b8
Wed Nov  5 21:04:16 2008: P[ 1]  * IND : Indication [3] from 412
Wed Nov  5 21:04:16 2008: P[ 2]  Transmitting 128 samples 2 misdn
Wed Nov  5 21:04:16 2008: P[ 1]  * IND :        ringing pid:75
Wed Nov  5 21:04:16 2008: P[ 2]  writing 128 bytes 2 asterisk



-- 
Olivier Fauchon
Freelance System-Network Admin
Phone: +33 610 493 763
http://www.aixmarseille.com




More information about the asterisk-users mailing list