[asterisk-users] PAP2T (or PAP2-NA or GrandStream 286) always busy on incoming calls with zaptel

Olivier MONNET olivier.monnet at altiva.fr
Sat Aug 19 09:46:27 MST 2006 

Hi,
Sorry for being this long to respond, but I have done some more testing.

This definitely does not come from the PAP2T, since the same error  
also occur with a PAP2-NA and a GrandStream 286.

I think It may come from the number I am using in the dialplan: 0917.  
Maybe this is associated with some special fonction? I cannot change  
because these are the last 4 digits from the 10 digits phone number  
that the carrier transmit.

It occur only with ZAPTEL, and not with call coming from SIP or IAX

This is the log of a call from a pstn phone:

Debug was enabled on PRI 1 and on ATA1 (which is the first ATA)

voip*CLI>
     -- Accepting voice call from '476767676' to '0917' on channel  
0/1, span 2
< Protocol Discriminator: Q.931 (8)  len=37
< Call Ref: len= 1 (reference 35/0x23) (Originator)
< Message type: SETUP (5)
< [04 03 80 90 a3]
< Bearer Capability (len= 5) [ Ext: 1  Q.931 Std: 0  Info transfer  
capability: Speech (0)
<                              Ext: 1  Trans mode/rate: 64kbps,  
circuit-mode (16)
<                              Ext: 1  User information layer 1: A- 
Law (35)
< [18 01 89]
< Channel ID (len= 3) [ Ext: 1  IntID: Implicit, Other Spare: 0,  
Exclusive Dchan: 0
<                        ChanSel: B1 channel
                          ]
< [1e 02 84 81]
< Progress Indicator (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard  
(0) 0: 0   Location: Public network serving the remote user (4)
<                               Ext: 1  Progress Description: Call is  
not end-to-end ISDN; further call progress information may be  
available inband. (1) ]
< [6c 0b 20 83 38 37 33 30 36 30 30 33 39]
< Calling Number (len=13) [ Ext: 0  TON: National Number (2)  NPI:  
Unknown Number Plan (0)
<                           Presentation: Presentation allowed of  
network provided number (3) '476767676' ]
< [70 05 81 30 39 31 37]
< Called Number (len= 7) [ Ext: 1  TON: Unknown Number Type (0)  NPI:  
ISDN/Telephony Numbering Plan (E.164/E.163) (1) '0917' ]
< [a1]
< Sending Complete (len= 1)
-- Making new call for cr 35
-- Processing Q.931 Call Setup
-- Processing IE 4 (cs0, Bearer Capability)
-- Processing IE 24 (cs0, Channel Identification)
-- Processing IE 30 (cs0, Progress Indicator)
-- Processing IE 108 (cs0, Calling Party Number)
-- Processing IE 112 (cs0, Called Party Number)
-- Processing IE 161 (cs0, Sending Complete)
 > Protocol Discriminator: Q.931 (8)  len=7
 > Call Ref: len= 1 (reference 163/0xA3) (Terminator)
 > Message type: CALL PROCEEDING (2)
 > [18 01 89]
 > Channel ID (len= 3) [ Ext: 1  IntID: Implicit, Other Spare: 0,  
Exclusive Dchan: 0
 >                        ChanSel: B1 channel
                          ]
     -- Accepting voice call from '476767676' to '0917' on channel  
0/1, span 1
     -- Executing Dial("Zap/4-1", "Sip/ata6&Sip/ata1&Sip/ata2&Sip/ 
ata3&Sip/ata4&Sip/ata5|120") in new stack
     -- Executing Dial("Zap/1-1", "Sip/ata6&Sip/ata1&Sip/ata2&Sip/ 
ata3&Sip/ata4&Sip/ata5|120") in new stack
     -- Called ata6
We're at 192.168.160.2 port 28900
Answering with capability 0x4 (ulaw)
12 headers, 8 lines
Reliably Transmitting:
INVITE sip:ata1 at 192.168.160.70:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK099f9483
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as52883cc5
To: <sip:ata1 at 192.168.160.70:5060>
Contact: <sip:476767676 at 192.168.160.2>
Call-ID: 4844a9661de5d36829020147427e0ea3 at 192.168.160.2
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Date: Sat, 19 Aug 2006 22:33:38 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER
Content-Type: application/sdp
Content-Length: 160

v=0
o=root 6463 6463 IN IP4 192.168.160.2
s=session
c=IN IP4 192.168.160.2
t=0 0
m=audio 28900 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -
  (no NAT) to 192.168.160.70:5060
     -- Called ata1
     -- Called ata6
We're at 192.168.160.2 port 25772
Answering with capability 0x4 (ulaw)
12 headers, 8 lines
Reliably Transmitting:
INVITE sip:ata1 at 192.168.160.70:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK26360aec
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as2016e735
To: <sip:ata1 at 192.168.160.70:5060>
Contact: <sip:476767676 at 192.168.160.2>
Call-ID: 5bbf0d050b4fe0b15c888d3651632394 at 192.168.160.2
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Date: Sat, 19 Aug 2006 22:33:38 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER
Content-Type: application/sdp
Content-Length: 160

v=0
o=root 6463 6463 IN IP4 192.168.160.2
s=session
c=IN IP4 192.168.160.2
t=0 0
m=audio 25772 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -
  (no NAT) to 192.168.160.70:5060
     -- Called ata1
     -- Called ata2
     -- Called ata3
     -- Called ata4
     -- Called ata5
     -- Called ata2
     -- Called ata3
     -- Called ata4
     -- Called ata5
voip*CLI>

Sip read:
SIP/2.0 100 Trying
To: <sip:ata1 at 192.168.160.70:5060>
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as52883cc5
Call-ID: 4844a9661de5d36829020147427e0ea3 at 192.168.160.2
CSeq: 102 INVITE
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK099f9483
Server: Linksys/PAP2-3.1.9(LSc)
Content-Length: 0


8 headers, 0 lines
voip*CLI>

Sip read:
SIP/2.0 100 Trying
To: <sip:ata1 at 192.168.160.70:5060>
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as2016e735
Call-ID: 5bbf0d050b4fe0b15c888d3651632394 at 192.168.160.2
CSeq: 102 INVITE
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK26360aec
Server: Linksys/PAP2-3.1.9(LSc)
Content-Length: 0


8 headers, 0 lines
     -- SIP/ata6-9fea is ringing
     -- Got SIP response 486 "Busy Here" back from 192.168.160.72
     -- SIP/ata6-eb1e is busy
     -- SIP/ata3-24c5 is ringing
voip*CLI>

Sip read:
SIP/2.0 180 Ringing
To: <sip:ata1 at 192.168.160.70:5060>;tag=906c41dc9fb94dcai0
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as52883cc5
Call-ID: 4844a9661de5d36829020147427e0ea3 at 192.168.160.2
CSeq: 102 INVITE
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK099f9483
Server: Linksys/PAP2-3.1.9(LSc)
Content-Length: 0


8 headers, 0 lines
     -- SIP/ata1-e320 is ringing
 > Protocol Discriminator: Q.931 (8)  len=8
 > Call Ref: len= 1 (reference 163/0xA3) (Terminator)
 > Message type: ALERTING (1)
 > [1e 02 81 88]
 > Progress Indicator (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard  
(0) 0: 0   Location: Private network serving the local user (1)
 >                               Ext: 1  Progress Description: Inband  
information or appropriate pattern now available. (8) ]    -- Got SIP  
response 486 "Busy Here" back from 192.168.160.71
     -- SIP/ata3-7f79 is busy


Sip read:
SIP/2.0 486 Busy Here
To: <sip:ata1 at 192.168.160.70:5060>;tag=7bfcc06d29bf2594i0
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as2016e735
Call-ID: 5bbf0d050b4fe0b15c888d3651632394 at 192.168.160.2
CSeq: 102 INVITE
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK26360aec
Server: Linksys/PAP2-3.1.9(LSc)
Content-Length: 0


8 headers, 0 lines
     -- Got SIP response 486 "Busy Here" back from 192.168.160.70
Transmitting:
ACK sip:ata1 at 192.168.160.70:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK26360aec
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as2016e735
To: <sip:ata1 at 192.168.160.70:5060>;tag=7bfcc06d29bf2594i0
Contact: <sip:476767676 at 192.168.160.2>
Call-ID: 5bbf0d050b4fe0b15c888d3651632394 at 192.168.160.2
CSeq: 102 ACK
User-Agent: Asterisk PBX
Content-Length: 0

  (no NAT) to 192.168.160.70:5060
     -- SIP/ata1-82dd is busy
Destroying call '5bbf0d050b4fe0b15c888d3651632394 at 192.168.160.2'
     -- SIP/ata4-53de is ringing
     -- SIP/ata5-afa0 is ringing
     -- SIP/ata2-d7bf is ringing
     -- Got SIP response 486 "Busy Here" back from 192.168.160.72
     -- SIP/ata5-e9c5 is busy
     -- Got SIP response 486 "Busy Here" back from 192.168.160.70
     -- Got SIP response 486 "Busy Here" back from 192.168.160.71
     -- SIP/ata2-7bad is busy
     -- SIP/ata4-8469 is busy
< Protocol Discriminator: Q.931 (8)  len=8
< Call Ref: len= 1 (reference 35/0x23) (Originator)
< Message type: RELEASE (77)
< [08 02 87 90]
< Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0    
Location: International network (7)
<                  Ext: 1  Cause: Normal Clearing (16), class =  
Normal Event (1) ]
-- Processing IE 8 (cs0, Cause)
     -- Channel 0/1, span 1 got hangup
     -- Channel 0/1, span 2 got hangup
   == Spawn extension (from-isdn, 0917, 1) exited non-zero on 'Zap/4-1'
     -- Hungup 'Zap/4-1'
Reliably Transmitting:
CANCEL sip:ata1 at 192.168.160.70:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK099f9483
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as52883cc5
To: <sip:ata1 at 192.168.160.70:5060>
Contact: <sip:476767676 at 192.168.160.2>
Call-ID: 4844a9661de5d36829020147427e0ea3 at 192.168.160.2
CSeq: 102 CANCEL
User-Agent: Asterisk PBX
Content-Length: 0

  (no NAT) to 192.168.160.70:5060
Scheduling destruction of call  
'4844a9661de5d36829020147427e0ea3 at 192.168.160.2' in 15000 ms
   == Spawn extension (from-isdn, 0917, 1) exited non-zero on 'Zap/1-1'
NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate  
Release Request
 > Protocol Discriminator: Q.931 (8)  len=8
 > Call Ref: len= 1 (reference 163/0xA3) (Terminator)
 > Message type: RELEASE COMPLETE (90)
 > [08 02 81 90]
 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0    
Location: Private network serving the local user (1)
 >                  Ext: 1  Cause: Normal Clearing (16), class =  
Normal Event (1) ]
NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null
     -- Hungup 'Zap/1-1'
voip*CLI>

Sip read:
SIP/2.0 487 Request Terminated
To: <sip:ata1 at 192.168.160.70:5060>;tag=906c41dc9fb94dcai0
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as52883cc5
Call-ID: 4844a9661de5d36829020147427e0ea3 at 192.168.160.2
CSeq: 102 INVITE
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK099f9483
Server: Linksys/PAP2-3.1.9(LSc)
Content-Length: 0


8 headers, 0 lines
Transmitting:
ACK sip:ata1 at 192.168.160.70:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK099f9483
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as52883cc5
To: <sip:ata1 at 192.168.160.70:5060>;tag=906c41dc9fb94dcai0
Contact: <sip:476767676 at 192.168.160.2>
Call-ID: 4844a9661de5d36829020147427e0ea3 at 192.168.160.2
CSeq: 102 ACK
User-Agent: Asterisk PBX
Content-Length: 0

  (no NAT) to 192.168.160.70:5060
voip*CLI>

Sip read:
SIP/2.0 200 OK
To: <sip:ata1 at 192.168.160.70:5060>;tag=906c41dc9fb94dcai0
From: "476767676" <sip:476767676 at 192.168.160.2>;tag=as52883cc5
Call-ID: 4844a9661de5d36829020147427e0ea3 at 192.168.160.2
CSeq: 102 CANCEL
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK099f9483
Server: Linksys/PAP2-3.1.9(LSc)
Content-Length: 0


8 headers, 0 lines
Destroying call '4844a9661de5d36829020147427e0ea3 at 192.168.160.2'
   == Primary D-Channel on span 2 down
   == Primary D-Channel on span 2 up
   == Primary D-Channel on span 1 down
   == Primary D-Channel on span 1 up
11 headers, 0 lines
Reliably Transmitting:
OPTIONS sip:ata1 at 192.168.160.70:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK23bc0c13
From: "asterisk" <sip:asterisk at 192.168.160.2>;tag=as7f4596f0
To: <sip:ata1 at 192.168.160.70:5060>
Contact: <sip:asterisk at 192.168.160.2>
Call-ID: 5c2b813a658c958b365efed93b265745 at 192.168.160.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Date: Sat, 19 Aug 2006 22:33:54 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER
Content-Length: 0

  (no NAT) to 192.168.160.70:5060
voip*CLI>

Sip read:
SIP/2.0 200 OK
To: <sip:ata1 at 192.168.160.70:5060>;tag=7bfcc06d29bf2594i0
From: "asterisk" <sip:asterisk at 192.168.160.2>;tag=as7f4596f0
Call-ID: 5c2b813a658c958b365efed93b265745 at 192.168.160.2
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 192.168.160.2:5060;branch=z9hG4bK23bc0c13
Server: Linksys/PAP2-3.1.9(LSc)
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura


10 headers, 0 lines
Destroying call '5c2b813a658c958b365efed93b265745 at 192.168.160.2'
   == Primary D-Channel on span 2 down

Do you see anything on this log?


Le 28 juil. 06 à 13:04, Joshua Colp a écrit :
----- Original Message -----
From: Olivier MONNET
[mailto:olivier.monnet at altiva.fr]
To: Asterisk Users Mailing List -
Non-Commercial Discussion [mailto:asterisk-users at lists.digium.com]
Sent:
Fri, 28 Jul 2006 05:11:35 -0300
Subject: [asterisk-users] PAP2T always busy
on incoming calls with zaptel


Hi,
I'm starting to use the new PAP2T instead of the old PAP2-NA for my
new installations.
I'm having a weird problem: when a call is comming from a zaptel
channel (from a bri with bristuff driver) the PAP2T say BUSY to the
SIP channel.

What's the exact SIP response the PAP2T gives? Might it be possible  
to get a sip debug on a pastebin so myself and others can examine the  
full dialog?


I have disabled all the features like DND and call forward.
If it's the last line for this number in the dialplan I can answer
the call normally, but I can't use voicemail, because it jump to it
each time.
I have installed about 50 PAP-NA and never had this kind of problem.
If the call is coming from an other PAP2T (via asterisk with
canreinvite=no), everything is fine.

This occur with asterisk 1.0.10 and 1.2.9.1

the firmware version for the PAP2T is 3.1.9(LSc)

I am using a dialplan coming from another customer with a similar
setup, but with PAP2-NA, where  it's working fine.

What can I do to fix this.

Regards,
Olivier


Joshua Colp
Digium
_______________________________________________
--Bandwidth and Colocation provided by Easynews.com --

asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
    http://lists.digium.com/mailman/listinfo/asterisk-users

More information about the asterisk-users mailing list