Call Progress Signal

[bohack]

I have a TA924 2nd gen with A2.06.00.E code. It is configured as a PRI gateway and trunks to my Asterisk server via SIP. Everything works as normal, however when the PBX the PRI is connected to does digit analysis on the phone number it takes the normal 1 to 2 seconds. When the gateway receives the phone number it takes an additional 1-2 seconds, then the asterisk server takes 1-2 seconds. Is there a way on the gateway to send a call progress tone to signal the user that the call is being placed, even though the SIP server has not yet placed the call? 5-6 seconds of silence is an eternity to an end user. My config is below (I've fuzzed the particulars). Please check my config... I was unclear on how to provide timing for the PBX (i.e. look like the telco provider).

Phone ----- (analog)----- PBX ------ (PRI)------ Gateway -----(SIP)---- Asterisk -----(SIP)---- Provider

Gateway#sh run

Building configuration...

!

!

! ADTRAN, Inc. OS version A2.06.00.E

! Boot ROM version 14.04.00

! Platform: Total Access 924 (2nd Gen), part number 4212924L1

!

!

hostname "Gateway"

enable password encrypted

!

clock timezone -5-Eastern-Time

!

ip subnet-zero

ip classless

ip routing

!

!no auto-config

!

event-history on

no logging forwarding

no logging email

!

service password-encryption

!

username "admin" password encrypted ""

!

!

!

no ip firewall alg msn

no ip firewall alg h323

!

no dot11ap access-point-control

!

interface eth 0/1

  ip address  10.120.1.2  255.255.0.0

  media-gateway ip primary

  no shutdown

!

interface t1 0/1

  shutdown

!

interface t1 0/2

  description PRI T1 for PBX

  tdm-group 1 timeslots 1-24 speed 64

  no shutdown

!

interface pri 1

  description pri 1

  connect t1 0/2 tdm-group 1

  role network b-channel-restarts disable

  no shutdown

!

interface fxs 0/1

  no shutdown

~~~~~~~~~

interface fxs 0/24

  no shutdown

!

isdn-group 1

  connect pri 1

!

!

ip route 0.0.0.0 0.0.0.0 10.120.1.1

!

ip tftp server

no ip tftp server overwrite

ip http server

ip http secure-server

no ip snmp agent

no ip ftp server

no ip scp server

no ip sntp server

!

voice feature-mode network

voice forward-mode network

!

voice codec-list PRI-Trunk

  codec g711ulaw

!

voice trunk T01 type sip

  sip-server primary 10.120.1.6

  registrar primary 10.120.1.6

  codec-group PRI-Trunk

  default-ring-cadence internal

!

voice trunk T02 type isdn

  resource-selection circular descending

  connect isdn-group 1

  rtp delay-mode adaptive

  codec-group PRI-Trunk

!

!

voice grouped-trunk PRI

  no description

  trunk T02

  accept 4125551234 cost 0

!

voice grouped-trunk SIP

  no description

  trunk T01

  accept $ cost 0

!

!

ip sip

!

ip sip registrar

no ip sip registrar authenticate

!

line con 0

  login

  password encrypted

  line-timeout 240

!

line telnet 0 4

  login

  password encrypted

  line-timeout 240

  no shutdown

line ssh 0 4

  login local-userlist

  line-timeout 240

  no shutdown

!

end

[Anonymous]

Hello Bohack,

Thanks for posting in our forum.  I would like to see a debug from the ADTRAN point of view first.  Can you enable the following debugs from the CLI in the ADTRAN:

debug sip stack message

debug voice switch

debug voice summary

debug isdn l2-for

Make sure you run all these debugs on the same window/session.  Also, you may want to set your program to save the output to a .txt file or increase the buffer size.  Another thing to do is to enlarge the session window so the debug does not get truncated and put on the next line.

Once these debugs have been entered, make a call.  I want to review the debug output so I can see the call flow.  The sip debug handles sip messages, isdn l2-for displays Q.931 messages, and the voice debugs show some internal call routing in the ADTRAN.  I will be better able to answer your question after seeing this debug information.

Thanks,

Geoff

[bohack]

The debug below is for both the PBX and the gateway. The PBX is nothing more than an analog set connected to the FXS port and it's simulating the our PBX. The Gateway is the PRI to VOIP conversion that will eventually connect to our PBX and provide timing, just as the network would provide timing today. Both outputs are below... The test call was to 4128095397 both date clocks are synced to a time server.

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2012.06.08 13:40:22 =~=~=~=~=~=~=~=~=~=~=~=

PBX#

PBX#debug sip stack message

PBX#debug voice switch

PBX#debug voice summary

PBX#debug isdn l2-for

PBX#

13:43:23:969 VOICE.SUMMARY voice user 7243078369 cos allowed the call to Extensions

13:43:23:970 SB.CALL 32 Idle                 Called the call routine with 4128095397

13:43:23 SB.TGMgr Testing TrunkGroup PRI for Call SABR Routing Permissions

13:43:23 SB.TGMgr TrunkGroup PRI is Permitted for SABR Routing

13:43:23 SB.TGMgr For dialed number 4128095397, against template NXX-NXX-XXXX, on TrunkGroup PRI, the score is 1000

13:43:23:972 SB.CCM isMappable:

13:43:23:973 SB.CCM  :  Call Struct 0x2644810 :   Call-ID = 32

13:43:23:974 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:43:23:974 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/0.0

13:43:23:975 SB.CCM  :  Org TID = Fxs   Dst TID =

13:43:23:975 SB.CCM isMappable: Call Connection Type is TDM_TO_TDM

13:43:23:976 SB.CALL 32 Idle                 Call sent from 7243078369 to T02 (4128095397)

13:43:23:976 VOICE.SUMMARY 7243078369 is calling T02 (4128095397).

13:43:23:977 SB.CALL 32 State change      >> Idle->Delivering

13:43:23:978 SB.CALL 32 Delivering           Called the deliverResponse routine from Delivering

13:43:23:979 SB.CALL 32 Delivering           DeliverResponse(accept) sent from T02 to 7243078369

13:43:23 ISDN.L2_FMT PRI  1  =====================================================

13:43:23 ISDN.L2_FMT PRI  1  Sent = Sapi:00  C/R:R Tei:00

13:43:23 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:93   Nr:106

13:43:23 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:001D

13:43:23 ISDN.L2_FMT PRI  1         M - 05 SETUP      

13:43:23 ISDN.L2_FMT PRI  1          IE - 04 BEARER CAPABILITY   Len=3

13:43:23 ISDN.L2_FMT PRI  1               80 Xfer Cap.:SPEECH           

13:43:23 ISDN.L2_FMT PRI  1               90 Xfer Rate:64k  

13:43:23 ISDN.L2_FMT PRI  1               A2 Layer 1:u-Law         

13:43:23 ISDN.L2_FMT PRI  1          IE - 18 CHANNEL ID          Len=3

13:43:23 ISDN.L2_FMT PRI  1               A1 Primary Rate

13:43:23 ISDN.L2_FMT PRI  1                  Intfc ID:IMPLICIT

13:43:23 ISDN.L2_FMT PRI  1                  Pref/Excl:PREFERRED

13:43:23 ISDN.L2_FMT PRI  1                  D-Chan Indicated:NO

13:43:23 ISDN.L2_FMT PRI  1                  Chan. Sel:FOLLOWS

13:43:23 ISDN.L2_FMT PRI  1               83 Numb/Map:NUMBER

13:43:23 ISDN.L2_FMT PRI  1               92 Channel:18

13:43:23 ISDN.L2_FMT PRI  1          IE - 6C CALLING PARTY #     Len=12

13:43:23 ISDN.L2_FMT PRI  1               00 Numb. Type:UNKNOWN      

13:43:23 ISDN.L2_FMT PRI  1                  Numb. Plan:UNKNOWN       

13:43:23 ISDN.L2_FMT PRI  1               80 Presentation:ALLOWED    

13:43:23 ISDN.L2_FMT PRI  1                  Ph.# 7243078369

13:43:23 ISDN.L2_FMT PRI  1          IE - 70 CALLED PARTY #      Len=11

13:43:23 ISDN.L2_FMT PRI  1               80 Numb. Type:UNKNOWN      

13:43:23 ISDN.L2_FMT PRI  1                  Numb. Plan:UNKNOWN       

13:43:23 ISDN.L2_FMT PRI  1                  Ph.# 4128095397

13:43:24 ISDN.L2_FMT PRI  1  =====================================================

13:43:24 ISDN.L2_FMT PRI  1  Recd = Sapi:00  C/R:C Tei:00

13:43:24 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:106   Nr:94

13:43:24 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:24 ISDN.L2_FMT PRI  1         M - 02 CALL_PROC  

13:43:24 ISDN.L2_FMT PRI  1          IE - 18 CHANNEL ID          Len=3

13:43:24 ISDN.L2_FMT PRI  1               A9 Primary Rate

13:43:24 ISDN.L2_FMT PRI  1                  Intfc ID:IMPLICIT

13:43:24 ISDN.L2_FMT PRI  1                  Pref/Excl:EXCLUSIVE

13:43:24 ISDN.L2_FMT PRI  1                  D-Chan Indicated:NO

13:43:24 ISDN.L2_FMT PRI  1                  Chan. Sel:FOLLOWS

13:43:24 ISDN.L2_FMT PRI  1               83 Numb/Map:NUMBER

13:43:24 ISDN.L2_FMT PRI  1               92 Channel:18

13:43:27 ISDN.L2_FMT PRI  1  =====================================================

13:43:27 ISDN.L2_FMT PRI  1  Recd = Sapi:00  C/R:C Tei:00

13:43:27 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:107   Nr:94

13:43:27 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:27 ISDN.L2_FMT PRI  1         M - 03 PROGRESS   

13:43:27 ISDN.L2_FMT PRI  1          IE - 1E PROGRESS INDICATOR  Len=2

13:43:27 ISDN.L2_FMT PRI  1               82 Location:LN

13:43:27 ISDN.L2_FMT PRI  1               88 Description:INBAND AUDIO AVAIL

13:43:28:001 SB.CALL 32 State change      >> Delivering->PreConnecting

13:43:28:002 SB.CALL 32 PreConnecting        Call PreConnecting from T02 to 7243078369

13:43:28:003 SB.CCM connect:

13:43:28:003 SB.CCM  :  Call Struct 0x2644810 :   Call-ID = 32

13:43:28:004 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:43:28:004 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/2.18

13:43:28:005 SB.CCM  :  Org TID = Fxs   Dst TID = Ds1Ds0Usage

13:43:28:005 SB.CCM connect: Call Connection Type is TDM_TO_TDM

13:43:28:006 SB.CCM connect: TDM streams: Table Fxs 0/1.0 to Table Ds1Ds0Usage 0/2.18

13:43:28:007 SB.CALL 32 State change      >> PreConnecting->PreConnected

13:43:28:007 SB.CALL 32 PreConnected         Call PreConnecting from 7243078369 to T02

13:43:31 ISDN.L2_FMT PRI  1  =====================================================

13:43:31 ISDN.L2_FMT PRI  1  Recd = Sapi:00  C/R:C Tei:00

13:43:31 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:108   Nr:94

13:43:31 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:31 ISDN.L2_FMT PRI  1         M - 07 CONNECT    

13:43:31 ISDN.L2_FMT PRI  1  =====================================================

13:43:31 ISDN.L2_FMT PRI  1  Sent = Sapi:00  C/R:R Tei:00

13:43:31 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:94   Nr:109

13:43:31 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:001D

13:43:31 ISDN.L2_FMT PRI  1         M - 0F CONNECT_ACK

13:43:31:523 SB.CALL 32 PreConnected         Called the connect routine

13:43:31:524 SB.CALL 32 State change      >> PreConnected->Connecting

13:43:31:525 SB.CALL 32 Connecting           Connect sent from T02 to 7243078369

13:43:31:525 SB.CALL 32 Connecting           Called the connectResponse routine

13:43:31:526 SB.CCM connect:

13:43:31:526 SB.CCM  :  Call Struct 0x2644810 :   Call-ID = 32

13:43:31:527 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:43:31:527 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/2.18

13:43:31:528 SB.CCM  :  Org TID = Fxs   Dst TID = Ds1Ds0Usage

13:43:31:528 SB.CCM connect: Call Connection Type is TDM_TO_TDM

13:43:31:529 SB.CCM connect: TDM streams: Table Fxs 0/1.0 to Table Ds1Ds0Usage 0/2.18

13:43:31:530 SB.CALL 32 State change      >> Connecting->Connected

13:43:31:530 VOICE.SUMMARY 7243078369 is connected to T02 (4128095397)

13:43:31:531 SB.CALL 32 Connected            ConnectResponse sent from 7243078369 to T02

13:43:35 ISDN.L2_FMT PRI  1  =====================================================

13:43:35 ISDN.L2_FMT PRI  1  Recd = Sapi:00  C/R:C Tei:00

13:43:35 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:109   Nr:95

13:43:35 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:35 ISDN.L2_FMT PRI  1         M - 45 DISCONNECT 

13:43:35 ISDN.L2_FMT PRI  1          IE - 08 CAUSE               Len=2

13:43:35 ISDN.L2_FMT PRI  1               82 Location:LN

13:43:35 ISDN.L2_FMT PRI  1               90 Cause:16 (NORMAL_CLEARING)

13:43:35 ISDN.L2_FMT PRI  1  =====================================================

13:43:35 ISDN.L2_FMT PRI  1  Sent = Sapi:00  C/R:R Tei:00

13:43:35 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:95   Nr:110

13:43:35 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:001D

13:43:35 ISDN.L2_FMT PRI  1         M - 4D RELEASE    

13:43:35:484 VOICE.SUMMARY Call from 7243078369 to T02 (4128095397) ended by T02: normal clearing

13:43:35:484 SB.CALL 32 Connected            Called the clearCall routine

13:43:35:485 SB.CALL 32 Connected            ClearCall sent from T02 to 7243078369

13:43:35:486 SB.CALL 32 State change      >> Connected->Clearing

13:43:35:487 SB.CALL 32 Clearing             Called the clearResponse routine

13:43:35:487 SB.CALL 32 State change      >> Clearing->CallIdlePending

13:43:35:488 SB.CCM disconnect:

13:43:35:488 SB.CCM  :  Call Struct 0x2644810 :   Call-ID = 32

13:43:35:489 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:43:35:489 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/2.18

13:43:35:489 SB.CCM  :  Org TID = Fxs   Dst TID = Ds1Ds0Usage

13:43:35:490 SB.CCM disconnect: Call Connection Type is TDM_TO_TDM

13:43:35:490 SB.CCM disconnect: Disconnecting TDM streams

13:43:35:491 SB.CCM release:

13:43:35:491 SB.CCM  :  Call Struct 0x2644810 :   Call-ID = 32

13:43:35:492 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:43:35:492 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/2.18

13:43:35:493 SB.CCM  :  Org TID = Fxs   Dst TID = Ds1Ds0Usage

13:43:35:494 SB.CCM release: Call Connection Type is TDM_TO_TDM

13:43:35:495 SB.CALL 32 CallIdlePending      ClearResponse sent from 7243078369 to T02

13:43:35 ISDN.L2_FMT PRI  1  =====================================================

13:43:35 ISDN.L2_FMT PRI  1  Recd = Sapi:00  C/R:C Tei:00

13:43:35 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:110   Nr:96

13:43:35 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:35 ISDN.L2_FMT PRI  1         M - 5A RELEASE_CMP

PBX#

PBX#

PBX#undeb

PBX#undebug all

PBX#exit

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2012.06.08 13:39:34 =~=~=~=~=~=~=~=~=~=~=~=

Gateway#debug sip stack message

Gateway#debug voice switch

Gateway#debug voice summary

Gateway#debug isdn l2-for

Gateway#

13:43:23 ISDN.L2_FMT PRI  1  =====================================================

13:43:23 ISDN.L2_FMT PRI  1  Recd = Sapi:00  C/R:R Tei:00

13:43:23 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:93   Nr:106

13:43:23 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:001D

13:43:23 ISDN.L2_FMT PRI  1         M - 05 SETUP      

13:43:23 ISDN.L2_FMT PRI  1          IE - 04 BEARER CAPABILITY   Len=3

13:43:23 ISDN.L2_FMT PRI  1               80 Xfer Cap.:SPEECH           

13:43:23 ISDN.L2_FMT PRI  1               90 Xfer Rate:64k  

13:43:23 ISDN.L2_FMT PRI  1               A2 Layer 1:u-Law         

13:43:23 ISDN.L2_FMT PRI  1          IE - 18 CHANNEL ID          Len=3

13:43:23 ISDN.L2_FMT PRI  1               A1 Primary Rate

13:43:23 ISDN.L2_FMT PRI  1                  Intfc ID:IMPLICIT

13:43:23 ISDN.L2_FMT PRI  1                  Pref/Excl:PREFERRED

13:43:23 ISDN.L2_FMT PRI  1                  D-Chan Indicated:NO

13:43:23 ISDN.L2_FMT PRI  1                  Chan. Sel:FOLLOWS

13:43:23 ISDN.L2_FMT PRI  1               83 Numb/Map:NUMBER

13:43:23 ISDN.L2_FMT PRI  1               92 Channel:18

13:43:23 ISDN.L2_FMT PRI  1          IE - 6C CALLING PARTY #     Len=12

13:43:23 ISDN.L2_FMT PRI  1               00 Numb. Type:UNKNOWN      

13:43:23 ISDN.L2_FMT PRI  1                  Numb. Plan:UNKNOWN       

13:43:23 ISDN.L2_FMT PRI  1               80 Presentation:ALLOWED    

13:43:23 ISDN.L2_FMT PRI  1                  Ph.# 7243078369

13:43:23 ISDN.L2_FMT PRI  1          IE - 70 CALLED PARTY #      Len=11

13:43:23 ISDN.L2_FMT PRI  1               80 Numb. Type:UNKNOWN      

13:43:23 ISDN.L2_FMT PRI  1                  Numb. Plan:UNKNOWN       

13:43:23 ISDN.L2_FMT PRI  1                  Ph.# 4128095397

13:43:23 ISDN.L2_FMT PRI  1  =====================================================

13:43:23 ISDN.L2_FMT PRI  1  Sent = Sapi:00  C/R:C Tei:00

13:43:23 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:106   Nr:94

13:43:23 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:23 ISDN.L2_FMT PRI  1         M - 02 CALL_PROC  

13:43:23 ISDN.L2_FMT PRI  1          IE - 18 CHANNEL ID          Len=3

13:43:23 ISDN.L2_FMT PRI  1               A9 Primary Rate

13:43:23 ISDN.L2_FMT PRI  1                  Intfc ID:IMPLICIT

13:43:23 ISDN.L2_FMT PRI  1                  Pref/Excl:EXCLUSIVE

13:43:23 ISDN.L2_FMT PRI  1                  D-Chan Indicated:NO

13:43:23 ISDN.L2_FMT PRI  1                  Chan. Sel:FOLLOWS

13:43:23 ISDN.L2_FMT PRI  1               83 Numb/Map:NUMBER

13:43:23 ISDN.L2_FMT PRI  1               92 Channel:18

13:43:23:754 SB.CALL 34 Idle                 Called the call routine with 4128095397

13:43:23 SB.TGMgr Testing TrunkGroup PRI for Call SABR Routing Permissions

13:43:23 SB.TGMgr TrunkGroup PRI is Permitted for SABR Routing

13:43:23 SB.TGMgr Testing TrunkGroup SIP for Call SABR Routing Permissions

13:43:23 SB.TGMgr TrunkGroup SIP is Permitted for SABR Routing

13:43:23 SB.TGMgr For dialed number 4128095397, against template $, on TrunkGroup SIP, the score is 500

13:43:23:757 SB.CCM isMappable:

13:43:23:757 SB.CCM  :  Call Struct 0x2687a10 :   Call-ID = 34

13:43:23:758 SB.CCM  :  Org Acct = T02    Dst Acct = T01

13:43:23:758 SB.CCM  :  Org Port ID = 0/2.18   Dst Port ID = 0/0.0

13:43:23:759 SB.CCM  :  Org TID = Ds1Ds0Usage   Dst TID =

13:43:23:759 SB.CCM isMappable: Call Connection Type is TDM_TO_RTP

13:43:23:761 SB.CCM isMappable: Reserving RTP Channel 0/1.1

13:43:23:761 SB.CCM isMappable: Creating SDP Offer

13:43:23:763 SB.CCM getBestMatchCodecList: PCMU

13:43:23:765 SB.CALL 34 Idle                 Call sent from T02 to T01 (4128095397)

13:43:23:765 VOICE.SUMMARY T02 is calling T01 (4128095397).

13:43:23:766 SB.CALL 34 State change      >> Idle->Delivering

13:43:23 SIP.STACK MSG     Tx: UDP src=10.2.2.8:5060 dst=10.10.1.196:5060

13:43:23 SIP.STACK MSG         INVITE sip:4128095397@10.10.1.196:5060 SIP/2.0

13:43:23 SIP.STACK MSG         From: <sip:7243078369@10.10.1.196:5060;transport=UDP>;tag=23e0d50-0-13c4-2ec52-75284e1d-2ec52

13:43:23 SIP.STACK MSG         To: <sip:4128095397@10.10.1.196:5060>

13:43:23 SIP.STACK MSG         Call-ID: 23f09b0-0-13c4-2ec52-5a0163a1-2ec52@10.10.1.196

13:43:23 SIP.STACK MSG         CSeq: 1 INVITE

13:43:23 SIP.STACK MSG         Via: SIP/2.0/UDP 10.2.2.8:5060;branch=z9hG4bK-2ec52-b6b2419-37e14190

13:43:23 SIP.STACK MSG         Max-Forwards: 70

13:43:23 SIP.STACK MSG         Supported: 100rel,replaces

13:43:23 SIP.STACK MSG         Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER, REGISTER

13:43:23 SIP.STACK MSG         User-Agent: ADTRAN_Total_Access_924_2nd_Gen/A2.06.00.E

13:43:23 SIP.STACK MSG         Contact: <sip:7243078369@10.2.2.8:5060;transport=UDP>

13:43:23 SIP.STACK MSG         Content-Type: application/SDP

13:43:23 SIP.STACK MSG         Content-Length: 209

13:43:23 SIP.STACK MSG    

13:43:23 SIP.STACK MSG         v=0

13:43:23 SIP.STACK MSG         o=- 1339177403 1339177403 IN IP4 10.2.2.8

13:43:23 SIP.STACK MSG         s=-

13:43:23 SIP.STACK MSG         c=IN IP4 10.2.2.8

13:43:23 SIP.STACK MSG         t=0 0

13:43:23 SIP.STACK MSG         m=audio 10000 RTP/AVP 0 101

13:43:23 SIP.STACK MSG         a=rtpmap:0 PCMU/8000

13:43:23 SIP.STACK MSG         a=silenceSupp:off - - - -

13:43:23 SIP.STACK MSG         a=rtpmap:101 telephone-event/8000

13:43:23 SIP.STACK MSG         a=fmtp:101 0-15

13:43:23 SIP.STACK MSG    

13:43:23 SIP.STACK MSG     Rx: UDP src=10.10.1.196:5060 dst=10.2.2.8:5060

13:43:23 SIP.STACK MSG         SIP/2.0 100 Trying

13:43:23 SIP.STACK MSG         Via: SIP/2.0/UDP 10.2.2.8:5060;branch=z9hG4bK-2ec52-b6b2419-37e14190;received=10.2.2.8;rport=5060

13:43:23 SIP.STACK MSG         From: <sip:7243078369@10.10.1.196:5060;transport=UDP>;tag=23e0d50-0-13c4-2ec52-75284e1d-2ec52

13:43:23 SIP.STACK MSG         To: <sip:4128095397@10.10.1.196:5060>

13:43:23 SIP.STACK MSG         Call-ID: 23f09b0-0-13c4-2ec52-5a0163a1-2ec52@10.10.1.196

13:43:23 SIP.STACK MSG         CSeq: 1 INVITE

13:43:23 SIP.STACK MSG         Server: Asterisk PBX 1.8.13.0

13:43:23 SIP.STACK MSG         Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

13:43:23 SIP.STACK MSG         Supported: replaces, timer

13:43:23 SIP.STACK MSG         Contact: <sip:4128095397@10.10.1.196:5060>

13:43:23 SIP.STACK MSG         Content-Length: 0

13:43:23 SIP.STACK MSG    

13:43:23:801 SB.CALL 34 Delivering           Called the deliverResponse routine from Delivering

13:43:23:802 SB.CALL 34 Delivering           DeliverResponse(accept) sent from T01 to T02

13:43:27 SIP.STACK MSG     Rx: UDP src=10.10.1.196:5060 dst=10.2.2.8:5060

13:43:27 SIP.STACK MSG         SIP/2.0 183 Session Progress

13:43:27 SIP.STACK MSG         Via: SIP/2.0/UDP 10.2.2.8:5060;branch=z9hG4bK-2ec52-b6b2419-37e14190;received=10.2.2.8;rport=5060

13:43:27 SIP.STACK MSG         From: <sip:7243078369@10.10.1.196:5060;transport=UDP>;tag=23e0d50-0-13c4-2ec52-75284e1d-2ec52

13:43:27 SIP.STACK MSG         To: <sip:4128095397@10.10.1.196:5060>;tag=as2449da93

13:43:27 SIP.STACK MSG         Call-ID: 23f09b0-0-13c4-2ec52-5a0163a1-2ec52@10.10.1.196

13:43:27 SIP.STACK MSG         CSeq: 1 INVITE

13:43:27 SIP.STACK MSG         Server: Asterisk PBX 1.8.13.0

13:43:27 SIP.STACK MSG         Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

13:43:27 SIP.STACK MSG         Supported: replaces, timer

13:43:27 SIP.STACK MSG         Contact: <sip:4128095397@10.10.1.196:5060>

13:43:27 SIP.STACK MSG         Content-Type: application/sdp

13:43:27 SIP.STACK MSG         Content-Length: 258

13:43:27 SIP.STACK MSG    

13:43:27 SIP.STACK MSG         v=0

13:43:27 SIP.STACK MSG         o=root 88035830 88035830 IN IP4 10.10.1.196

13:43:27 SIP.STACK MSG         s=Asterisk PBX 1.8.13.0

13:43:27 SIP.STACK MSG         c=IN IP4 10.10.1.196

13:43:27 SIP.STACK MSG         t=0 0

13:43:27 SIP.STACK MSG         m=audio 10456 RTP/AVP 0 101

13:43:27 SIP.STACK MSG         a=rtpmap:0 PCMU/8000

13:43:27 SIP.STACK MSG         a=rtpmap:101 telephone-event/8000

13:43:27 SIP.STACK MSG         a=fmtp:101 0-16

13:43:27 SIP.STACK MSG         a=silenceSupp:off - - - -

13:43:27 SIP.STACK MSG         a=ptime:20

13:43:27 SIP.STACK MSG         a=sendrecv

13:43:27 SIP.STACK MSG    

13:43:27:700 SB.CALL 34 State change      >> Delivering->PreConnecting

13:43:27:701 SB.CALL 34 PreConnecting        Call PreConnecting from T01 to T02

13:43:27:702 SB.CCM connect:

13:43:27:702 SB.CCM  :  Call Struct 0x2687a10 :   Call-ID = 34

13:43:27:703 SB.CCM  :  Org Acct = T02    Dst Acct = T01

13:43:27:703 SB.CCM  :  Org Port ID = 0/2.18   Dst Port ID = 0/0.13

13:43:27:704 SB.CCM  :  Org TID = Ds1Ds0Usage   Dst TID =

13:43:27:704 SB.CCM  :  SDP Transaction = CallID: 34

13:43:27:705 SB.CCM  :  SDP Offer = 0x026ac010, (127.0.0.2:10000)

13:43:27:705 SB.CCM  :  SDP Answer = 0x026a9e10, (10.10.1.196:10456)

13:43:27:706 SB.CCM  :  RTP Channel = 0/1.1

13:43:27:706 SB.CCM connect: Call Connection Type is TDM_TO_RTP

13:43:27:708 SB.CCM connect: TDM streams: Table Ds1Ds0Usage 0/2.18 to Table 12368 0/1.1

13:43:27:709 SB.CCM connect: Undo of previous operation not required

13:43:27:710 SB.CCM getFinalCodec: PCMU

13:43:27:712 SB.CCM connect: Configuring RTP Channel 0/1.1 to 10.10.1.196:10456 via PCMU

13:43:27:712 SB.CCM connect:     fpp=2 echo=on dtmf=101/101 dscp=46 vad=off

13:43:27:713 VOICE.SUMMARY RTP for Call from 7243078369 to 4128095397:  Codec PCMU

13:43:27:713 SB.CCM connect: Starting RTP Channel

13:43:27:714 SB.CCM firewallConnectCall: No action taken, firewall traversal is not enabled

13:43:27:715 SB.CALL 34 State change      >> PreConnecting->PreConnected

13:43:27:715 SB.CALL 34 PreConnected         Call PreConnecting from T02 to T01

13:43:27 ISDN.L2_FMT PRI  1  =====================================================

13:43:27 ISDN.L2_FMT PRI  1  Sent = Sapi:00  C/R:C Tei:00

13:43:27 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:107   Nr:94

13:43:27 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:27 ISDN.L2_FMT PRI  1         M - 03 PROGRESS   

13:43:27 ISDN.L2_FMT PRI  1          IE - 1E PROGRESS INDICATOR  Len=2

13:43:27 ISDN.L2_FMT PRI  1               82 Location:LN

13:43:27 ISDN.L2_FMT PRI  1               88 Description:INBAND AUDIO AVAIL

13:43:31 SIP.STACK MSG     Rx: UDP src=10.10.1.196:5060 dst=10.2.2.8:5060

13:43:31 SIP.STACK MSG         SIP/2.0 200 OK

13:43:31 SIP.STACK MSG         Via: SIP/2.0/UDP 10.2.2.8:5060;branch=z9hG4bK-2ec52-b6b2419-37e14190;received=10.2.2.8;rport=5060

13:43:31 SIP.STACK MSG         From: <sip:7243078369@10.10.1.196:5060;transport=UDP>;tag=23e0d50-0-13c4-2ec52-75284e1d-2ec52

13:43:31 SIP.STACK MSG         To: <sip:4128095397@10.10.1.196:5060>;tag=as2449da93

13:43:31 SIP.STACK MSG         Call-ID: 23f09b0-0-13c4-2ec52-5a0163a1-2ec52@10.10.1.196

13:43:31 SIP.STACK MSG         CSeq: 1 INVITE

13:43:31 SIP.STACK MSG         Server: Asterisk PBX 1.8.13.0

13:43:31 SIP.STACK MSG         Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

13:43:31 SIP.STACK MSG         Supported: replaces, timer

13:43:31 SIP.STACK MSG         Contact: <sip:4128095397@10.10.1.196:5060>

13:43:31 SIP.STACK MSG         Content-Type: application/sdp

13:43:31 SIP.STACK MSG         Content-Length: 258

13:43:31 SIP.STACK MSG    

13:43:31 SIP.STACK MSG         v=0

13:43:31 SIP.STACK MSG         o=root 88035830 88035831 IN IP4 10.10.1.196

13:43:31 SIP.STACK MSG         s=Asterisk PBX 1.8.13.0

13:43:31 SIP.STACK MSG         c=IN IP4 10.10.1.196

13:43:31 SIP.STACK MSG         t=0 0

13:43:31 SIP.STACK MSG         m=audio 10456 RTP/AVP 0 101

13:43:31 SIP.STACK MSG         a=rtpmap:0 PCMU/8000

13:43:31 SIP.STACK MSG         a=rtpmap:101 telephone-event/8000

13:43:31 SIP.STACK MSG         a=fmtp:101 0-16

13:43:31 SIP.STACK MSG         a=silenceSupp:off - - - -

13:43:31 SIP.STACK MSG         a=ptime:20

13:43:31 SIP.STACK MSG         a=sendrecv

13:43:31 SIP.STACK MSG    

13:43:31:217 SB.CALL 34 PreConnected         Called the connect routine

13:43:31:217 SB.CALL 34 State change      >> PreConnected->Connecting

13:43:31:218 SB.CALL 34 Connecting           Connect sent from T01 to T02

13:43:31:219 SB.CALL 34 Connecting           Called the connectResponse routine

13:43:31:220 SB.CCM connect:

13:43:31:220 SB.CCM  :  Call Struct 0x2687a10 :   Call-ID = 34

13:43:31:221 SB.CCM  :  Org Acct = T02    Dst Acct = T01

13:43:31:221 SB.CCM  :  Org Port ID = 0/2.18   Dst Port ID = 0/0.13

13:43:31:222 SB.CCM  :  Org TID = Ds1Ds0Usage   Dst TID =

13:43:31:222 SB.CCM  :  SDP Transaction = CallID: 34

13:43:31:223 SB.CCM  :  SDP Offer = 0x026ac010, (127.0.0.2:10000)

13:43:31:224 SB.CCM  :  SDP Answer = 0x02685210, (10.10.1.196:10456)

13:43:31:224 SB.CCM  :  RTP Channel = 0/1.1

13:43:31:225 SB.CCM connect: Call Connection Type is TDM_TO_RTP

13:43:31:226 SB.CCM connect: TDM streams: Table Ds1Ds0Usage 0/2.18 to Table 12368 0/1.1

13:43:31:227 SB.CCM connect: Undo of previous operation not required

13:43:31:228 SB.CCM getFinalCodec: PCMU

13:43:31:230 SB.CCM connect: Configuring RTP Channel 0/1.1 to 10.10.1.196:10456 via PCMU

13:43:31:230 SB.CCM connect:     fpp=2 echo=on dtmf=101/101 dscp=46 vad=off

13:43:31:231 SB.CCM connect: No changes needed to RTP Channel

13:43:31:232 SB.CALL 34 State change      >> Connecting->Connected

13:43:31:232 VOICE.SUMMARY T02 is connected to T01 (4128095397)

13:43:31:233 SB.CALL 34 Connected            ConnectResponse sent from T02 to T01

13:43:31 SIP.STACK MSG     Tx: UDP src=10.2.2.8:5060 dst=10.10.1.196:5060

13:43:31 SIP.STACK MSG         ACK sip:4128095397@10.10.1.196:5060;transport=UDP SIP/2.0

13:43:31 SIP.STACK MSG         From: <sip:7243078369@10.10.1.196:5060;transport=UDP>;tag=23e0d50-0-13c4-2ec52-75284e1d-2ec52

13:43:31 SIP.STACK MSG         To: <sip:4128095397@10.10.1.196:5060>;tag=as2449da93

13:43:31 SIP.STACK MSG         Call-ID: 23f09b0-0-13c4-2ec52-5a0163a1-2ec52@10.10.1.196

13:43:31 SIP.STACK MSG         CSeq: 1 ACK

13:43:31 SIP.STACK MSG         Via: SIP/2.0/UDP 10.2.2.8:5060;branch=z9hG4bK-2ec5a-b6b413f-740930d9

13:43:31 SIP.STACK MSG         Max-Forwards: 70

13:43:31 SIP.STACK MSG         Supported: 100rel,replaces

13:43:31 SIP.STACK MSG         Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER, REGISTER

13:43:31 SIP.STACK MSG         User-Agent: ADTRAN_Total_Access_924_2nd_Gen/A2.06.00.E

13:43:31 SIP.STACK MSG         Contact: <sip:7243078369@10.2.2.8:5060;transport=UDP>

13:43:31 SIP.STACK MSG         Content-Length: 0

13:43:31 SIP.STACK MSG    

13:43:31 ISDN.L2_FMT PRI  1  =====================================================

13:43:31 ISDN.L2_FMT PRI  1  Sent = Sapi:00  C/R:C Tei:00

13:43:31 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:108   Nr:94

13:43:31 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:31 ISDN.L2_FMT PRI  1         M - 07 CONNECT    

13:43:31 ISDN.L2_FMT PRI  1  =====================================================

13:43:31 ISDN.L2_FMT PRI  1  Recd = Sapi:00  C/R:R Tei:00

13:43:31 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:94   Nr:109

13:43:31 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:001D

13:43:31 ISDN.L2_FMT PRI  1         M - 0F CONNECT_ACK

13:43:35 SIP.STACK MSG     Rx: UDP src=10.10.1.196:5060 dst=10.2.2.8:5060

13:43:35 SIP.STACK MSG         BYE sip:7243078369@10.2.2.8:5060;transport=UDP SIP/2.0

13:43:35 SIP.STACK MSG         Via: SIP/2.0/UDP 10.10.1.196:5060;branch=z9hG4bK43c74a9f;rport

13:43:35 SIP.STACK MSG         Max-Forwards: 70

13:43:35 SIP.STACK MSG         From: <sip:4128095397@10.10.1.196:5060>;tag=as2449da93

13:43:35 SIP.STACK MSG         To: <sip:7243078369@10.10.1.196:5060;transport=UDP>;tag=23e0d50-0-13c4-2ec52-75284e1d-2ec52

13:43:35 SIP.STACK MSG         Call-ID: 23f09b0-0-13c4-2ec52-5a0163a1-2ec52@10.10.1.196

13:43:35 SIP.STACK MSG         CSeq: 102 BYE

13:43:35 SIP.STACK MSG         User-Agent: Asterisk PBX 1.8.13.0

13:43:35 SIP.STACK MSG         X-Asterisk-HangupCause: Normal Clearing

13:43:35 SIP.STACK MSG         X-Asterisk-HangupCauseCode: 16

13:43:35 SIP.STACK MSG         Content-Length: 0

13:43:35 SIP.STACK MSG    

13:43:35 SIP.STACK MSG     Tx: UDP src=10.2.2.8:5060 dst=10.10.1.196:5060

13:43:35 SIP.STACK MSG         SIP/2.0 200 OK

13:43:35 SIP.STACK MSG         From: <sip:4128095397@10.10.1.196:5060>;tag=as2449da93

13:43:35 SIP.STACK MSG         To: <sip:7243078369@10.10.1.196:5060;transport=UDP>;tag=23e0d50-0-13c4-2ec52-75284e1d-2ec52

13:43:35 SIP.STACK MSG         Call-ID: 23f09b0-0-13c4-2ec52-5a0163a1-2ec52@10.10.1.196

13:43:35 SIP.STACK MSG         CSeq: 102 BYE

13:43:35 SIP.STACK MSG         Via: SIP/2.0/UDP 10.10.1.196:5060;rport=5060;branch=z9hG4bK43c74a9f

13:43:35 SIP.STACK MSG         Supported: 100rel,replaces

13:43:35 SIP.STACK MSG         Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER, REGISTER

13:43:35 SIP.STACK MSG         User-Agent: ADTRAN_Total_Access_924_2nd_Gen/A2.06.00.E

13:43:35 SIP.STACK MSG         Content-Length: 0

13:43:35 SIP.STACK MSG    

13:43:35:195 VOICE.SUMMARY Call from T02 to T01 (4128095397) ended by T01: normal clearing

13:43:35:195 SB.CALL 34 Connected            Called the clearCall routine

13:43:35:196 SB.CALL 34 Connected            ClearCall sent from T01 to T02

13:43:35:197 SB.CALL 34 State change      >> Connected->Clearing

13:43:35:198 SB.CALL 34 Clearing             Called the clearResponse routine

13:43:35:198 SB.CALL 34 State change      >> Clearing->CallIdlePending

13:43:35:199 SB.CCM disconnect:

13:43:35:199 SB.CCM  :  Call Struct 0x2687a10 :   Call-ID = 34

13:43:35:200 SB.CCM  :  Org Acct = T02    Dst Acct = T01

13:43:35:201 SB.CCM  :  Org Port ID = 0/2.18   Dst Port ID = 0/1.1

13:43:35:201 SB.CCM  :  Org TID = Ds1Ds0Usage   Dst TID =

13:43:35:202 SB.CCM  :  RTP Channel = 0/1.1

13:43:35:202 SB.CCM disconnect: Call Connection Type is TDM_TO_RTP

13:43:35:203 SB.CCM disconnect: Stopping RTP Channel 0/1.1

13:43:35:203 SB.CCM firewallDisconnectCall: No action taken, firewall traversal is not enabled

13:43:35:204 SB.CCM disconnect: Disconnecting TDM streams

13:43:35:204 SB.CCM release:

13:43:35:205 SB.CCM  :  Call Struct 0x2687a10 :   Call-ID = 34

13:43:35:205 SB.CCM  :  Org Acct = T02    Dst Acct = T01

13:43:35:206 SB.CCM  :  Org Port ID = 0/2.18   Dst Port ID = 0/1.1

13:43:35:206 SB.CCM  :  Org TID = Ds1Ds0Usage   Dst TID =

13:43:35:207 SB.CCM  :  RTP Channel = 0/1.1

13:43:35:207 SB.CCM release: Call Connection Type is TDM_TO_RTP

13:43:35:208 SB.CCM release: Releasing RTP Channel 0/1.1

13:43:35:208 SB.CALL 34 CallIdlePending      ClearResponse sent from T02 to T01

13:43:35 ISDN.L2_FMT PRI  1  =====================================================

13:43:35 ISDN.L2_FMT PRI  1  Sent = Sapi:00  C/R:C Tei:00

13:43:35 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:109   Nr:95

13:43:35 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:35 ISDN.L2_FMT PRI  1         M - 45 DISCONNECT 

13:43:35 ISDN.L2_FMT PRI  1          IE - 08 CAUSE               Len=2

13:43:35 ISDN.L2_FMT PRI  1               82 Location:LN

13:43:35 ISDN.L2_FMT PRI  1               90 Cause:16 (NORMAL_CLEARING)

13:43:35 ISDN.L2_FMT PRI  1  =====================================================

13:43:35 ISDN.L2_FMT PRI  1  Recd = Sapi:00  C/R:R Tei:00

13:43:35 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:95   Nr:110

13:43:35 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:001D

13:43:35 ISDN.L2_FMT PRI  1         M - 4D RELEASE    

13:43:35 ISDN.L2_FMT PRI  1  =====================================================

13:43:35 ISDN.L2_FMT PRI  1  Sent = Sapi:00  C/R:C Tei:00

13:43:35 ISDN.L2_FMT PRI  1         Ctl:INFO     Ns:110   Nr:96

13:43:35 ISDN.L2_FMT PRI  1         Prot:08  CRL:2  CRV:801D

13:43:35 ISDN.L2_FMT PRI  1         M - 5A RELEASE_CMP

13:43:41 SIP.STACK MSG     Rx: UDP src=10.10.1.196:5060 dst=10.2.2.8:5060

13:43:41 SIP.STACK MSG         OPTIONS sip:10.2.2.8 SIP/2.0

13:43:41 SIP.STACK MSG         Via: SIP/2.0/UDP 10.10.1.196:5060;branch=z9hG4bK032d6936;rport

13:43:41 SIP.STACK MSG         Max-Forwards: 70

13:43:41 SIP.STACK MSG         From: "asterisk" <sip:asterisk@pti.edu>;tag=as60faf870

13:43:41 SIP.STACK MSG         To: <sip:10.2.2.8>

13:43:41 SIP.STACK MSG         Contact: <sip:asterisk@10.10.1.196:5060>

13:43:41 SIP.STACK MSG         Call-ID: 10b9392e7e8aa85453e47d200ebddf5c@pti.edu

13:43:41 SIP.STACK MSG         CSeq: 102 OPTIONS

13:43:41 SIP.STACK MSG         User-Agent: Asterisk PBX 1.8.13.0

13:43:41 SIP.STACK MSG         Date: Fri, 08 Jun 2012 17:43:38 GMT

13:43:41 SIP.STACK MSG         Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

13:43:41 SIP.STACK MSG         Supported: replaces, timer

13:43:41 SIP.STACK MSG         Content-Length: 0

13:43:41 SIP.STACK MSG    

13:43:41 SIP.STACK MSG     Tx: UDP src=10.2.2.8:5060 dst=10.10.1.196:5060

13:43:41 SIP.STACK MSG         SIP/2.0 200 OK

13:43:41 SIP.STACK MSG         From: "asterisk"<sip:asterisk@pti.edu>;tag=as60faf870

13:43:41 SIP.STACK MSG         To: <sip:10.2.2.8>;tag=23e1150-0-13c4-2ec64-50371926-2ec64

13:43:41 SIP.STACK MSG         Call-ID: 10b9392e7e8aa85453e47d200ebddf5c@pti.edu

13:43:41 SIP.STACK MSG         CSeq: 102 OPTIONS

13:43:41 SIP.STACK MSG         Via: SIP/2.0/UDP 10.10.1.196:5060;rport=5060;branch=z9hG4bK032d6936

13:43:41 SIP.STACK MSG         Supported: 100rel,replaces

13:43:41 SIP.STACK MSG         Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER, REGISTER

13:43:41 SIP.STACK MSG         User-Agent: ADTRAN_Total_Access_924_2nd_Gen/A2.06.00.E

13:43:41 SIP.STACK MSG         Content-Length: 0

13:43:41 SIP.STACK MSG    

Gateway#undeb

Gateway#undebug all

Gateway#exit

[bohack]

After looking at all three units with the debug I noticed that the longest wait time was after the 10th digit was typed. There was almost a 4 second window where the adtran waited for a timeout to finish processing the 10 digit number. Is there a way to program the adtran to expect a 10 digit number and dial after the 10th digit?

See:

13:59:27:230 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (7) event

13:59:27:230 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(7) from PM

13:59:27:231 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

---longest wait---

13:59:31:231 SA.7243078369 Ca:0 State change      >> DigitGathering->DigitGathering

13:59:31:232 SA.7243078369 Ca:0 DigitGathering       sent: AcctPhoneMgr_cachg(CAS_Active) to PM

13:59:31:232 PM.0:1 State change      >> SendingDigits->Call Pending

13:59:31:233 SA.7243078369 Ca:0 DigitGathering       sent: call to SB

13:59:31:234 SA.7243078369 Ca:0 State change      >> DigitGathering->CallPending

Also see I'm not sure what that is and it's not part of this problem... I don't think:

13:59:34:731 TA.T02 ERROR! preConnectResponse ignored

Full output below:

PBX#

PBX#

PBX#

13:59:19:288 PM.0:1 Idle                 Processed OFFHOOK

13:59:19:288 PM.0:1 State change      >> Idle->Requesting Dialtone

13:59:19:289 SA.7243078369 Ca:0 Idle                 rcvd: AcctPhoneMgr_appearance(ON) from PM

13:59:19:290 SA.7243078369 Ca:0 State change      >> Idle->DigitGathering

13:59:19:291 SA.7243078369 Ca:0 DigitGathering       sent: AcctPhoneMgr_cachg(CAS_ReqDigits) to PM

13:59:19:291 PM.0:1 Requesting Dialtone  CACHG:ReqDigits on primary CA

13:59:19:292 PM.0:1 State change      >> Requesting Dialtone->SendingDigits

13:59:19:293 TONESERVICES.EVENTS fxs 0/1 - empty - Tone Detection: Request resource

13:59:19:294 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: DSP channel allocated for the resource

13:59:19:295 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: constructed

13:59:19:295 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: starting

13:59:19:296 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: TDM map

13:59:19:793 TONESERVICES.EVENTS fxs 0/1 - empty - DialTone Generation: Request resource

13:59:19:794 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - DialTone Generation: DSP channel allocated for the resource

13:59:19:795 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - DialTone Generation: constructed

13:59:19:795 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - DialTone Generation: starting

13:59:19:796 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - DialTone Generation: TDM map

13:59:22:589 PM.0:1 SendingDigits        Digit 4 processed

13:59:22:590 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (4) event

13:59:22:591 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - DialTone Generation: stopping

13:59:22:591 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - DialTone Generation: TDM unmap

13:59:22:592 RTP.CHANNEL fxs 0/1 - dsp 0/1.1 - DialTone Generation: releasing RTP resource

13:59:22:593 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - DialTone Generation: release

13:59:22:593 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(4) from PM

13:59:22:594 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 second(s) for more digits

13:59:22:938 PM.0:1 SendingDigits        Digit 1 processed

13:59:22:940 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (1) event

13:59:22:940 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(1) from PM

13:59:22:941 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:23:428 PM.0:1 SendingDigits        Digit 2 processed

13:59:23:430 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (2) event

13:59:23:430 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(2) from PM

13:59:23:431 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:24:158 PM.0:1 SendingDigits        Digit 8 processed

13:59:24:160 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (8) event

13:59:24:160 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(8) from PM

13:59:24:161 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:24:478 PM.0:1 SendingDigits        Digit 0 processed

13:59:24:480 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (0) event

13:59:24:480 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(0) from PM

13:59:24:481 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:24:838 PM.0:1 SendingDigits        Digit 9 processed

13:59:24:840 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (9) event

13:59:24:840 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(9) from PM

13:59:24:841 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:25:488 PM.0:1 SendingDigits        Digit 5 processed

13:59:25:490 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (5) event

13:59:25:490 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(5) from PM

13:59:25:491 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:26:068 PM.0:1 SendingDigits        Digit 3 processed

13:59:26:070 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (3) event

13:59:26:070 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(3) from PM

13:59:26:071 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:26:628 PM.0:1 SendingDigits        Digit 9 processed

13:59:26:630 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (9) event

13:59:26:630 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(9) from PM

13:59:26:631 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:27:228 PM.0:1 SendingDigits        Digit 7 processed

13:59:27:230 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: received digit (7) event

13:59:27:230 SA.7243078369 Ca:0 DigitGathering       rcvd: AcctPhoneMgr_dialDigit(7) from PM

13:59:27:231 SA.7243078369 Ca:0 DigitGathering       Named-digit-timeout waiting 0 seconds for more digits

13:59:31:231 SA.7243078369 Ca:0 State change      >> DigitGathering->DigitGathering

13:59:31:232 SA.7243078369 Ca:0 DigitGathering       sent: AcctPhoneMgr_cachg(CAS_Active) to PM

13:59:31:232 PM.0:1 State change      >> SendingDigits->Call Pending

13:59:31:233 SA.7243078369 Ca:0 DigitGathering       sent: call to SB

13:59:31:234 SA.7243078369 Ca:0 State change      >> DigitGathering->CallPending

13:59:31:235 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: stopping

13:59:31:235 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: TDM unmap

13:59:31:236 RTP.CHANNEL fxs 0/1 - dsp 0/1.1 - Tone Detection: releasing RTP resource

13:59:31:236 TONESERVICES.EVENTS fxs 0/1 - dsp 0/1.1 - Tone Detection: release

13:59:31:237 SA.7243078369 rcvd: AcctPhoneMgr_billingCode from PM

13:59:31:238 SB.CALL 35 Idle                 Called the call routine with 4128095397

13:59:31 SB.TGMgr Testing TrunkGroup PRI for Call SABR Routing Permissions

13:59:31 SB.TGMgr TrunkGroup PRI is Permitted for SABR Routing

13:59:31 SB.TGMgr For dialed number 4128095397, against template NXX-NXX-XXXX, on TrunkGroup PRI, the score is 1000

13:59:31:240 SB.CCM isMappable:

13:59:31:241 SB.CCM  :  Call Struct 0x266cc10 :   Call-ID = 35

13:59:31:241 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:59:31:242 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/0.0

13:59:31:243 SB.CCM  :  Org TID = Fxs   Dst TID =

13:59:31:243 SB.CCM isMappable: Call Connection Type is TDM_TO_TDM

13:59:31:244 SB.CALL 35 Idle                 Call sent from 7243078369 to T02 (4128095397)

13:59:31:244 SB.CALL 35 State change      >> Idle->Delivering

13:59:31:245 SA.7243078369 Ca:0 CallPending          rcvd: callResponse from SB

13:59:31:245 SA.7243078369 Ca:0 State change      >> CallPending->Calling

13:59:31:246 TA.T02 15 State change      >> TAIdle->TAOutGoing (TAS_Delivering)

13:59:31:247 TM.T02 15 tachg_Delivering

13:59:31:248 TM.T02 15 IsdnTmStateIdle->IsdnTmStateOutboundDeliver

13:59:31:248 TM.T02 15 IsdnTmStateOutboundDeliver::enter()

13:59:31:249 SB.CALL 35 Delivering           Called the deliverResponse routine from Delivering

13:59:31:250 SB.CALL 35 Delivering           DeliverResponse(accept) sent from T02 to 7243078369

13:59:31:251 SA.7243078369 Ca:0 Calling              rcvd: deliverResponse from SB

13:59:31:251 SA.7243078369 Ca:0 Calling              sent: AcctPhoneMgr_info to PM

13:59:31:252 PM.0:1 ERROR! APM_Info ignored

13:59:34:717 TM.T02 15 IsdnTmStateOutboundDeliver->IsdnTmStateOutboundPreconnect

13:59:34:718 TM.T02 15 IsdnTmStateOutboundPreconnect::enter()

13:59:34:718 TA.T02 15 TAOutGoing           rcvd: preConnect from TM

13:59:34:719 SB.CALL 35 State change      >> Delivering->PreConnecting

13:59:34:720 SB.CALL 35 PreConnecting        Call PreConnecting from T02 to 7243078369

13:59:34:721 SA.7243078369 Ca:0 Calling              rcvd: preConnect from SB

13:59:34:721 SA.7243078369 Ca:0 State change      >> Calling->Alerting

13:59:34:722 SA.7243078369 Ca:0 Alerting             sent: AcctPhoneMgr_preconnect to PM

13:59:34:722 PM.0:1 Call Pending         Preconnect handled.

13:59:34:723 PM.0:1 Call Pending         processed CACHG:Connected

13:59:34:723 PM.0:1 State change      >> Call Pending->Connected

13:59:34:724 SA.7243078369 sent: preConnectResponse(pass) to SB

13:59:34:724 SA.7243078369 Ca:0 Alerting             rcvd: AcctPhoneMgr_connect from PM

13:59:34:725 SB.CCM connect:

13:59:34:726 SB.CCM  :  Call Struct 0x266cc10 :   Call-ID = 35

13:59:34:726 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:59:34:727 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/2.15

13:59:34:727 SB.CCM  :  Org TID = Fxs   Dst TID = Ds1Ds0Usage

13:59:34:728 SB.CCM connect: Call Connection Type is TDM_TO_TDM

13:59:34:728 SB.CCM connect: TDM streams: Table Fxs 0/1.0 to Table Ds1Ds0Usage 0/2.15

13:59:34:730 SB.CALL 35 State change      >> PreConnecting->PreConnected

13:59:34:730 SB.CALL 35 PreConnected         Call PreConnecting from 7243078369 to T02

13:59:34:731 TA.T02 ERROR! preConnectResponse ignored

13:59:37:328 PM.0:1 Connected            Processed ONHOOK

13:59:37:328 PM.0:1 State change      >> Connected->Idle

13:59:37:329 SA.7243078369 Ca:0 Alerting             rcvd: AcctPhoneMgr_appearance(OFF) from PM

13:59:37:330 SA.7243078369 Ca:0 Alerting             sent: clearCall to SB

13:59:37:330 SA.7243078369 Ca:0 State change      >> Alerting->Clearing

13:59:37:331 SA.7243078369 rcvd: AcctPhoneMgr_COSOverride from PM

13:59:37:332 SB.CALL 35 PreConnected         Called the clearCall routine

13:59:37:332 SB.CALL 35 State change      >> PreConnected->Clearing

13:59:37:333 SB.CALL 35 Clearing             ClearCall sent from 7243078369 to T02

13:59:37:333 TA.T02 15 TAOutGoing           ClearCall event accepted

13:59:37:334 TA.T02 15 State change      >> TAOutGoing->TAClearingComplete (TAS_Clearing)

13:59:37:335 TM.T02 15 IsdnTmStateOutboundPreconnect->IsdnTmStateUserClearing

13:59:37:335 TM.T02 15 IsdnTmStateUserClearing::enter()

13:59:37:336 SB.CALL 35 Clearing             Called the clearResponse routine

13:59:37:337 SB.CALL 35 State change      >> Clearing->CallIdlePending

13:59:37:337 SB.CCM disconnect:

13:59:37:338 SB.CCM  :  Call Struct 0x266cc10 :   Call-ID = 35

13:59:37:338 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:59:37:339 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/2.15

13:59:37:340 SB.CCM  :  Org TID = Fxs   Dst TID = Ds1Ds0Usage

13:59:37:340 SB.CCM disconnect: Call Connection Type is TDM_TO_TDM

13:59:37:341 SB.CCM disconnect: Disconnecting TDM streams

13:59:37:341 SB.CCM release:

13:59:37:342 SB.CCM  :  Call Struct 0x266cc10 :   Call-ID = 35

13:59:37:342 SB.CCM  :  Org Acct = 7243078369    Dst Acct = T02

13:59:37:343 SB.CCM  :  Org Port ID = 0/1.0   Dst Port ID = 0/2.15

13:59:37:344 SB.CCM  :  Org TID = Fxs   Dst TID = Ds1Ds0Usage

13:59:37:344 SB.CCM release: Call Connection Type is TDM_TO_TDM

13:59:37:345 SB.CALL 35 CallIdlePending      ClearResponse sent from T02 to 7243078369

13:59:37:345 SA.7243078369 Ca:0 Clearing             rcvd: clearResponse from SB

13:59:37:346 SA.7243078369 Ca:0 State change      >> Clearing->Idle

13:59:37:346 SA.7243078369 Ca:0 Idle                 sent: AcctPhoneMgr_cachg(CAS_Idle) to PM

13:59:37:347 PM.0:1 Idle                 Dropped CACHG w/Call State not RINGING

13:59:37:377 TM.T02 15 IsdnTmStateUserClearing->IsdnTmStateIdling

13:59:37:378 TM.T02 15 IsdnTmStateIdling::enter()

13:59:37:378 TM.T02 15 IsdnTmStateIdling - send appearance off

13:59:37:379 TM.T02 15 IsdnTmStateIdling->IsdnTmStateIdle

13:59:37:380 TM.T02 15 IsdnAppearanceChannel::releaseChannel

13:59:37:380 TM.T02 15 IsdnTmStateIdle::enter()

13:59:37:381 TA.T02 15 TAClearingComplete   rcvd: appearance off from TM

13:59:37:382 TA.T02 15 TAClearingComplete   Clear Local Variables

13:59:37:382 TA.T02 15 State change      >> TAClearingComplete->TAIdle (TAS_Idle)

2012.06.08 13:59:38 SMDR 35         06/08/2012 13:59:31      0.1 0    I  00/01                 7243078369      00/02 T02                                                  4128095397      0 N

[bohack]

After testing last night with our actual PBX everything worked fine. So I believe the actual problem is the Adtran waiting too long for the next digit and timing out, then dialing. How do you configure the Adtran to either shorten the time waited for the last digit or to dial on a predetermined number of digits? Let say 4 digit dialing is after the 4th digit but if it's escaped with a 9 it will wait for the next 10 digits?

[Anonymous]

Hello,

There are three ways (two which are practical) to speed up the routing of that 10 digit number:

1.  create a dial-plan entry

2.  decrease the voice timeouts interdigit

3.  press # after dialing the number so if will immediately route

When dialing from an analog FXS port, the ADTRAN will use the dial-plan to determine if a number is complete.  If the dialed numbers match a dial-plan entry, then the ADTRAN will immediately route the call/dialed numbers.  If the dialed numbers do not match a dial-plan entry, then the ADTRAN will wait the interdigit timeout period before routing the call.

The interdigit timeout is a timer that comes into play after 1 digit is dialed/pressed.  It is 4 seconds by default.  As soon as someone dials a number from the FXS port, they have 4 seconds to dial/press another digit.  If another digit is not pressed within 4 seconds, the ADTRAN will attempt to route the call.  If this timeout is lowered to 2 seconds, then a string of dialed numbers will be routed faster, but people only have 2 seconds in between digits when dialing a number and 2 seconds may be too short of a time.

Anytime the # number is pressed on a phone connected to the FXS port, the ADTRAN will immediately route the call.  A # is seen as the end of a number.  It may not be reasonable to expect people to hit # after dialing, but I wanted you to know about this.

Here are some example config lines that may help:

voice dial-plan 5 long-distance NXX-NXX-XXXX

voice timeouts interdigit 3

When creating dial-plan entries, you have to be aware of the numbers the end users are dialing.  If they are in a 7 and 10 digit dialing area, then dial-plan entries can cause problems since 7 and 10 digit patterns often overlap.  For example:

voice dial-plan 2 local NXX-XXXX

voice dial-plan 3 long-distance NXX-NXX-XXXX

No one would be able to able to dial 10 digit numbers with the above config because the first seven numbers in each pattern match.  The first 7 digits of any number string beginning with 2-8 would automatically be routed after 7 digits. I think for your case a single dial-plan entry like dial-plan 5 should speed things up a bit.

Let me know if you have any questions.

Regards,

Geoff

[Anonymous]

Hello,

I went ahead and flagged this post as “Assumed Answered.” If any of the responses on this thread assisted you, please mark them as either Correct or Helpful answers with the applicable buttons. This will make them visible and help other members of the community find solutions more easily. If you still need assistance, I would be more than happy to continue working with you on this - just let me know in a reply.

Regards,

Geoff