[Home]

Summary:ASTERISK-08602: not able to send/receive calls after upgrade
Reporter:andrea lanza (lanzaandrea)Labels:
Date Opened:2007-01-18 04:42:25.000-0600Date Closed:2011-06-07 14:00:22
Priority:BlockerRegression?No
Status:Closed/CompleteComponents:Channels/chan_misdn
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:I am using chan_misdn; I upgaded kernel, asterisk and chan_misdn.
(Please no comment on stupidity of upgrading an happyly running asterisk...
I already told myself any kind of bad things...)

Now I am no more able to send / receive any calls.
The problem seeems to be in the oad - dad part of the ISDN protocol.
In the past I had similar problem (see http://bugs.digium.com/bug_view_advanced_page.php?bug_id=7317)
At that time, in the end we agreed it was a problem of my PSTN provider,
sometimes sending indication dnumplan 0 and sometimes sending indication dnumplan=2.
Now it is 3....!
My question is: is it possible that my provider changed from these 2 random states dnumplan
to a third one EXACTLY in the moment I upgraded my box ?
Isn't more realistic that my setup in some way might induce my provider to change this dnumplan setting ???

I tried almost any kind of combination of
dialplan=0 ...to 4
localdialplan=0 ....to 4
cpndialplan=0 ...to 4
without seeing any appreciable change.

now I have in my misdn.conf as it was: (2 TE ports; no NT Ports)

[general]
debug=3
;debug=0
tracefile=/var/log/asterisk/misdn.log
append_digits2exten=yes
bridging=yes

[default]
method=round_robin
;method=standard
context=from-pstn
;context=default
language=it
dialplan=0
localdialplan=0
cpndialplan=0
nationalprefix=
internationalprefix=
senddtmf=yes

rxgain=0
txgain=0
te_choose_channel=yes
immediate=yes
;always_immediate=yes

[TEports]
context=from-pstn
ports=1,2
msns=*

;[NTports]
;context=outgoing
;ports=3,4


here is the output for

asterisk01*CLI> misdn show config
Misdn General-Config:
-> Version: chan_misdn-0.3.0
-> misdn_init: /etc/misdn-init.conf -> debug: 3
-> tracefile: /var/log/asterisk/misdn.log -> bridging: yes
-> stop_tone_after_first_digit: yes -> append_digits2exten: yes
-> dynamic_crypt: no                -> crypt_prefix:
-> crypt_keys:                      -> ntdebugflags: 0
-> ntdebugfile: /var/log/misdn-nt.log

[PORT 1]
-> name: TEports                    -> allowed_bearers: all
-> far_alerting: no                 -> rxgain: 0
-> txgain: 0                        -> te_choose_channel: yes
-> pmp_l1_check: no                 -> reject_cause: 21
-> block_on_alarm: no               -> hdlc: no
-> context: from-pstn               -> language: it
-> musicclass: default              -> callerid:
-> method: round_robin              -> dialplan: 0
-> localdialplan: 0                 -> cpndialplan: 0
-> nationalprefix:                  -> internationalprefix:
-> presentation: -1                 -> screen: -1
-> always_immediate: no             -> nodialtone: no
-> immediate: yes                   -> senddtmf: yes
-> hold_allowed: no                 -> early_bconnect: yes
-> incoming_early_audio: no         -> echocancel: 0
-> name: TEports                    -> need_more_infos: no
-> nttimeout: no                    -> jitterbuffer: 4000
-> jitterbuffer_upper_threshold: 0  -> callgroup:
-> pickupgroup:                     -> msns: *
-> ptp: no

[PORT 2]
-> name: TEports                    -> allowed_bearers: all
-> far_alerting: no                 -> rxgain: 0
-> txgain: 0                        -> te_choose_channel: yes
-> pmp_l1_check: no                 -> reject_cause: 21
-> block_on_alarm: no               -> hdlc: no
-> context: from-pstn               -> language: it
-> musicclass: default              -> callerid:
-> method: round_robin              -> dialplan: 0
-> localdialplan: 0                 -> cpndialplan: 0
-> nationalprefix:                  -> internationalprefix:
-> presentation: -1                 -> screen: -1
-> always_immediate: no             -> nodialtone: no
-> immediate: yes                   -> senddtmf: yes
-> hold_allowed: no                 -> early_bconnect: yes
-> incoming_early_audio: no         -> echocancel: 0
-> name: TEports                    -> need_more_infos: no
-> nttimeout: no                    -> jitterbuffer: 4000
-> jitterbuffer_upper_threshold: 0  -> callgroup:
-> pickupgroup:                     -> msns: *
-> ptp: no


and here it is the trace setting debug=3 for an incoming call

FROM 0104695467
TO   0108680567

here is the debug=3 trace,

delete old file
asterisk01:/etc/asterisk # rm /var/log/asterisk/misdn.log
place call
asterisk01:/etc/asterisk # cat /var/log/asterisk/misdn.log

Thu Jan 18 11:21:45 2007: P[ 1]  set_channel: bc->channel:0 channel:1
Thu Jan 18 11:21:45 2007: P[ 1]  I IND :SETUP oad:*****p
                                                       0108680567?0??567?0,No dad:08680567?0??567?0,Noop(UNIQUEI pid:18 state:none
Thu Jan 18 11:21:45 2007: P[ 1]   --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Thu Jan 18 11:21:45 2007: P[ 1]   --> info_dad: onumplan:2 dnumplan:3 rnumplan:  cpnnumplan:0
Thu Jan 18 11:21:45 2007: P[ 1]   --> caps:Unknown Bearer pi:0 keypad: sending_complete:0
Thu Jan 18 11:21:45 2007: P[ 1]   --> Bearer: Unknown Bearer
Thu Jan 18 11:21:45 2007: P[ 1]   --> Codec: Alaw
Thu Jan 18 11:21:45 2007: P[ 0]   --> * NEW CHANNEL dad:08680567?0??567?0,Noop(UNIQUEI oad:*****p
                                                                                                0108680567?0??567?0,No
Thu Jan 18 11:21:45 2007: P[ 1]   --> CTON: Unknown
Thu Jan 18 11:21:45 2007: P[ 1]   --> EXPORT_PID: pid:18
Thu Jan 18 11:21:45 2007: P[ 1]   --> PRES: Restricted (1)
Thu Jan 18 11:21:45 2007: P[ 1]   --> SCREEN: Unscreened (0)
Thu Jan 18 11:21:45 2007: P[ 1]  Extension can never match, so disconnecting
Thu Jan 18 11:21:45 2007: P[ 1]  I SEND:RELEASE oad:*****p
                                                         0108680567?0??567?0,No dad:08680567?0??567?0,Noop(UNIQUEI pid:18
Thu Jan 18 11:21:45 2007: P[ 1]   --> channel:1 mode:TE cause:16 ocause:1 rad: cad:
Thu Jan 18 11:21:45 2007: P[ 1]   --> info_dad: onumplan:2 dnumplan:3 rnumplan:  cpnnumplan:0
Thu Jan 18 11:21:45 2007: P[ 1]   --> caps:Unknown Bearer pi:0 keypad: sending_complete:0
Thu Jan 18 11:21:45 2007: P[ 1]  $$$ CLEANUP CALLED pid:18
Thu Jan 18 11:21:45 2007: P[ 1]  I IND :RELEASE_COMPLETE oad: dad: pid:18 state:EXTCANTMATCH
Thu Jan 18 11:21:45 2007: P[ 1]   --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
Thu Jan 18 11:21:45 2007: P[ 1]   --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
Thu Jan 18 11:21:45 2007: P[ 1]   --> caps:Speech pi:0 keypad: sending_complete:0
Thu Jan 18 11:21:45 2007: P[ 1]   --> hangup
Thu Jan 18 11:21:45 2007: P[ 1]  * IND : HANGUP pid:18 ctx:from-pstn dad:08680567?0??567?0,Noop(UNIQUEI oad:*****p
                                                                                                                 0108680567?0??567?0,No State:EXTCANTMATCH
Thu Jan 18 11:21:45 2007: P[ 1]   --> l3id:2000c
Thu Jan 18 11:21:45 2007: P[ 1]   --> cause:16
Thu Jan 18 11:21:45 2007: P[ 1]   --> out_cause:16
Thu Jan 18 11:21:45 2007: P[ 1]   --> state:EXTCANTMATCH
Thu Jan 18 11:21:45 2007: P[ 1]   --> Channel: mISDN/1-1 hanguped new state:CLEANING
Thu Jan 18 11:21:45 2007: P[ 1]  $$$ CLEANUP CALLED pid:18
Thu Jan 18 11:21:45 2007: P[ 2]  set_channel: bc->channel:0 channel:1
Thu Jan 18 11:21:45 2007: P[ 2]  I IND :SETUP oad:*****p
                                                       0108680567?0??567?0,No dad:08680567?0??567?0,Noop(UNIQUEI pid:19 state:none
Thu Jan 18 11:21:45 2007: P[ 2]   --> channel:1 mode:TE cause:16 ocause:16 rad: cad:
Thu Jan 18 11:21:45 2007: P[ 2]   --> info_dad: onumplan:2 dnumplan:3 rnumplan:  cpnnumplan:0
Thu Jan 18 11:21:45 2007: P[ 2]   --> caps:Unknown Bearer pi:0 keypad: sending_complete:0
Thu Jan 18 11:21:45 2007: P[ 2]   --> Bearer: Unknown Bearer
Thu Jan 18 11:21:45 2007: P[ 2]   --> Codec: Alaw
Thu Jan 18 11:21:45 2007: P[ 0]   --> * NEW CHANNEL dad:08680567?0??567?0,Noop(UNIQUEI oad:*****p
                                                                                                0108680567?0??567?0,No
Thu Jan 18 11:21:45 2007: P[ 2]   --> CTON: Unknown
Thu Jan 18 11:21:45 2007: P[ 2]   --> EXPORT_PID: pid:19
Thu Jan 18 11:21:45 2007: P[ 2]   --> PRES: Restricted (1)
Thu Jan 18 11:21:45 2007: P[ 2]   --> SCREEN: Unscreened (0)
Thu Jan 18 11:21:45 2007: P[ 2]  Extension can never match, so disconnecting
Thu Jan 18 11:21:45 2007: P[ 2]  I SEND:RELEASE oad:*****p
                                                         0108680567?0??567?0,No dad:08680567?0??567?0,Noop(UNIQUEI pid:19
Thu Jan 18 11:21:45 2007: P[ 2]   --> channel:1 mode:TE cause:16 ocause:1 rad: cad:
Thu Jan 18 11:21:45 2007: P[ 2]   --> info_dad: onumplan:2 dnumplan:3 rnumplan:  cpnnumplan:0
Thu Jan 18 11:21:45 2007: P[ 2]   --> caps:Unknown Bearer pi:0 keypad: sending_complete:0
Thu Jan 18 11:21:45 2007: P[ 2]  $$$ CLEANUP CALLED pid:19
Thu Jan 18 11:21:45 2007: P[ 2]  I IND :RELEASE_COMPLETE oad: dad: pid:19 state:EXTCANTMATCH
Thu Jan 18 11:21:45 2007: P[ 2]   --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
Thu Jan 18 11:21:45 2007: P[ 2]   --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
Thu Jan 18 11:21:45 2007: P[ 2]   --> caps:Speech pi:0 keypad: sending_complete:0
Thu Jan 18 11:21:45 2007: P[ 2]   --> hangup
Thu Jan 18 11:21:45 2007: P[ 2]  * IND : HANGUP pid:19 ctx:from-pstn dad:08680567?0??567?0,Noop(UNIQUEI oad:*****p
                                                                                                                 0108680567?0??567?0,No State:EXTCANTMATCH
Thu Jan 18 11:21:45 2007: P[ 2]   --> l3id:4000c
Thu Jan 18 11:21:45 2007: P[ 2]   --> cause:16
Thu Jan 18 11:21:45 2007: P[ 2]   --> out_cause:16
Thu Jan 18 11:21:45 2007: P[ 2]   --> state:EXTCANTMATCH
Thu Jan 18 11:21:45 2007: P[ 2]   --> Channel: mISDN/2-1 hanguped new state:CLEANING
Thu Jan 18 11:21:45 2007: P[ 2]  $$$ CLEANUP CALLED pid:19

the asterisk console shows the same (on a following call from the same phone to the same destination)


P[ 1] set_channel: bc->channel:0 channel:2
P[ 1] I IND :SETUP oad:04695467p
                               ?0108680567?0,Noop(U dad:08680567?0,Noop(UNIQUEID=${UNI pid:22 state:none
P[ 1]  --> channel:2 mode:TE cause:16 ocause:16 rad: cad:
P[ 1]  --> info_dad: onumplan:3 dnumplan:3 rnumplan:  cpnnumplan:0
P[ 1]  --> caps:Unknown Bearer pi:c keypad: sending_complete:0
P[ 1]  --> Bearer: Unknown Bearer
P[ 1]  --> Codec: Alaw
P[ 0]  --> * NEW CHANNEL dad:08680567?0,Noop(UNIQUEID=${UNI oad:04695467p
                                                                        ?0108680567?0,Noop(U
P[ 1]  --> CTON: Unknown
P[ 1]  --> EXPORT_PID: pid:22
P[ 1]  --> PRES: Restricted (1)
P[ 1]  --> SCREEN: Unscreened (0)
P[ 1] I SEND:RELEASE oad:04695467p
                                 ?0108680567?0,Noop(U dad:08680567?0,Noop(UNIQUEID=${UNI pid:22
P[ 1]  --> channel:2 mode:TE cause:16 ocause:1 rad: cad:
P[ 1]  --> info_dad: onumplan:3 dnumplan:3 rnumplan:  cpnnumplan:0
P[ 1]  --> caps:Unknown Bearer pi:c keypad: sending_complete:0
P[ 1] MGMT: SSTATUS: L2_ESTABLISH
P[ 1] $$$ CLEANUP CALLED pid:22
P[ 1] I IND :RELEASE_COMPLETE oad: dad: pid:22 state:EXTCANTMATCH
P[ 1]  --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
P[ 1]  --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
P[ 1]  --> caps:Speech pi:0 keypad: sending_complete:0
P[ 1]  --> hangup
P[ 1] * IND : HANGUP    pid:22 ctx:from-pstn dad:08680567?0,Noop(UNIQUEID=${UNI oad:04695467p
                                                                                            ?0108680567?0,Noop(U State:EXTCANTMATCH
P[ 1]  --> l3id:2000e
P[ 1]  --> cause:16
P[ 1]  --> out_cause:16
P[ 1]  --> state:EXTCANTMATCH
P[ 1]  --> Channel: mISDN/1-2 hanguped new state:CLEANING
P[ 1] $$$ CLEANUP CALLED pid:22
P[ 2] set_channel: bc->channel:0 channel:-1
P[ 2] I IND :SETUP oad:04695467p
                               ?0108680567?567?0,No dad:08680567?567?0,Noop(UNIQUEID=$ pid:23 state:none
P[ 2]  --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
P[ 2]  --> info_dad: onumplan:3 dnumplan:3 rnumplan:  cpnnumplan:0
P[ 2]  --> caps:Unknown Bearer pi:0 keypad: sending_complete:0
P[ 2]  --> Bearer: Unknown Bearer
P[ 2]  --> Codec: Alaw
P[ 0]  --> * NEW CHANNEL dad:08680567?567?0,Noop(UNIQUEID=$ oad:04695467p
                                                                        ?0108680567?567?0,No
P[ 2]  --> CTON: Unknown
P[ 2]  --> EXPORT_PID: pid:23
P[ 2]  --> PRES: Restricted (1)
P[ 2]  --> SCREEN: Unscreened (0)
P[ 2] I SEND:RELEASE oad:04695467p
                                 ?0108680567?567?0,No dad:08680567?567?0,Noop(UNIQUEID=$ pid:23
P[ 2]  --> channel:0 mode:TE cause:16 ocause:1 rad: cad:
P[ 2]  --> info_dad: onumplan:3 dnumplan:3 rnumplan:  cpnnumplan:0
P[ 2]  --> caps:Unknown Bearer pi:0 keypad: sending_complete:0
P[ 2] MGMT: SSTATUS: L2_ESTABLISH
P[ 2] $$$ CLEANUP CALLED pid:23
P[ 2] I IND :RELEASE_COMPLETE oad: dad: pid:23 state:EXTCANTMATCH
P[ 2]  --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
P[ 2]  --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
P[ 2]  --> caps:Speech pi:0 keypad: sending_complete:0
P[ 2]  --> hangup
P[ 2] * IND : HANGUP    pid:23 ctx:from-pstn dad:08680567?567?0,Noop(UNIQUEID=$ oad:04695467p
                                                                                            ?0108680567?567?0,No State:EXTCANTMATCH
P[ 2]  --> l3id:4000e
P[ 2]  --> cause:16
P[ 2]  --> out_cause:16
P[ 2]  --> state:EXTCANTMATCH
P[ 2]  --> Channel: mISDN/2-u11 hanguped new state:CLEANING
P[ 2] $$$ CLEANUP CALLED pid:23

of cource extension can never match, I have entryes
for 01086805XX and for 001086805XX (dnumplan=0 or 2)
but NO Entryes for 08680567....!
Yes, i can add this, but triple the inbound rules it's not so fantastic...

Moreover placing external calls is no more possible:

from an internal extension (567), calling 00104695467 (first zero is trpped away,
then 010469546 is sent to the misdn trunk)
......
   -- Executing Set("SIP/567-08234d08", "the_num=0104695467") in new stack
   -- Executing Dial("SIP/567-08234d08", "misdn/1/0104695467|300|") in new stack
P[ 0]  --> * NEW CHANNEL dad:0104695467 oad:(null)
P[ 1]  --> TON: Unknown
P[ 1]  --> LTON: Unknown
P[ 1]  --> CTON: Unknown
P[ 1] * CALL: 1/0104695467
P[ 1]  --> * dad:0104695467 tech:mISDN/1-u12 ctx:from-pstn
P[ 1]  --> * adding2newbc ext 0104695467
P[ 1]  --> * adding2newbc callerid 567
P[ 1]  --> pres: -1 screen: -1
P[ 1]  --> pres: 0
P[ 1]  --> PRES: Allowed (0x0)
P[ 1]  --> SCREEN: Unscreened (0x0)
P[ 1] NO OPTS GIVEN
P[ 1] I SEND:SETUP oad:567 dad:0104695467 pid:24
P[ 1]  --> channel:0 mode:TE cause:16 ocause:16 rad: cad:
P[ 1]  --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
P[ 1]  --> caps:Speech pi:0 keypad: sending_complete:0
P[ 1]  --> found chan: 1
P[ 1]  -->  found channel: 1
P[ 1] --> new_l3id 50001
P[ 1]  --> * SEND: State Dialing pid:24
   -- Called 1/0104695467
P[ 1] MGMT: SSTATUS: L2_ESTABLISH
P[ 1] $$$ CLEANUP CALLED pid:24
P[ 1] I IND :RELEASE_COMPLETE oad: dad: pid:24 state:CALLING
P[ 1]  --> channel:0 mode:TE cause:1 ocause:16 rad: cad:
P[ 1]  --> info_dad: onumplan:0 dnumplan:0 rnumplan:0 cpnnumplan:0
P[ 1]  --> caps:Speech pi:0 keypad: sending_complete:0
P[ 1]  --> queue_hangup
P[ 1] * RELEASING CHANNEL pid:24 ctx:from-pstn dad:0104695467 oad:00104695467 state: CALLING
P[ 1]  --> * State Down
P[ 1]  --> Setting AST State to down
P[ 1] $$$ CLEANUP CALLED pid:24
 == Everyone is busy/congested at this time (1:0/0/1)

What can I check ????

My box is a Suse Linux 10.0. uname -a output is:
Linux asterisk01 2.6.13-15.13-smp #1 SMP Tue Nov 28 13:43:50 UTC 2006 i686 i686 i386 GNU/Linux

asterisk, as said is the last 1-2 svn version:
Connected to Asterisk SVN-branch-1.2-r51197M currently running on asterisk01 (pid = 6495)

Thanks,
Andrea



Comments:By: andrea lanza (lanzaandrea) 2007-01-18 06:57:02.000-0600

I tryed to attach my bo to another provider (TELECOM Italia instead of Fastweb) calling from a cellualar.
No changes, always
onumplan:3 dnumplan:3

So I can absolutely exclude a problem in my provider (Fastweb)
I can only exclude any modification to misdn.conf or the init script to
start misdn

so I think it could be
1) a kernel upgrade issue
2) a misdn_chan upgrade issue

Another thing, but I can be absolutely wrong: in the past it seems to me
than chan_misdn.so went into /usr/lib/asterisk/modules when I run make into
install-misdn-mqueue ; now it "appears" just compiling asterisk...
By: crich (crich) 2007-01-18 06:59:38.000-0600

I'm  very sorry but this is not a bug. It looks like your provider is messing something up, but we should move this discussion to the misdn mailinglist which you can find on www.misdn.org
By: andrea lanza (lanzaandrea) 2007-01-18 07:41:26.000-0600

Sorry but I not agree with you......
I changed provider and no changes occurred

I was writing this simple test:

in extensions.conf:
[from-pstn]
exten => _.,1,NoOp(I am in from-pstn _.  they called ${EXTEN})
i call and see:

   -- Executing NoOp("mISDN/1-u41", "I am in from-pstn _.  they called 08680567??567?0,Noop(UNIQUEID=") in new stack

on hungap:

   -- Executing NoOp("mISDN/1-u41", "I am in from-pstn _.  they called h") in new stack


it seems to me that it is a copy buffer problem, not a provider problem
it seems some software is trying to NoOp something in wrong way...
By: crich (crich) 2007-01-18 08:07:39.000-0600

i don't understand what your test does really. In the Hangup exetnsion the ${EXTEN} variable equals to 'h' allways.
By: andrea lanza (lanzaandrea) 2007-01-18 08:21:01.000-0600

yes, and you see "h"
but on incoming calls, why I see THAT exetnsion called ?
Executing NoOp("mISDN/1-u41", "I am in from-pstn _. they called 08680567??567?0,Noop(UNIQUEID=") in new stack
shouldn't I see something like:
Executing NoOp("mISDN/1-u41", "I am in from-pstn _. they called 08680567") in new stack
What are that extra characters appearing after the extension (no matter
08680567 instead of 0108680567 or 00108680567 in this moment..)
By: andrea lanza (lanzaandrea) 2007-01-18 09:56:00.000-0600

SOLVED !

I performed a new installation of asterisk and mISDN taking care of doing

cd /usr/src/linux
make cloneconfig
cd /usr/src/linux
make menuconfig
****Simply tell the menuconfig program to quit, and have it save the .config file
make modules_prepare

I noticed that yesterday installation of mISDN went into
/lib/modules/2.6.13-15.12-smp/extra
instead of
/lib/modules/2.6.13-15.13-smp/extra
(consider yesterday I upgraded the kernel, reboot the machine, verified
/usr/src/linux and /usr/src/linux-2.6 pointed to the correct
linux-2.6.13-15.13 release, but.....)
i think the problem could be :
YESTERDAY I just typed
make && make install in the install-misdn-mqueue,
so actually nothing were recompiled.
Now I performed a
make clean && make && make install and everything is OK
( I receive incoming call for 0108680567, coming from 0104695467...)

Perhaps a little check in the beronet install-misdn-mqueue could avoid
this problem to other people, or perhaps to say to always perform a
make clean && make && make install

thanks all for attention, and sorry if I was not kind !

could be set to closed

Andrea
By: Serge Vecher (serge-v) 2007-01-24 13:44:55.000-0600

morale of the story: always use 'make clean' on upgrades (oh, wait, we knew that already).