Adtran
Help
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Show  only  | Search instead for 
Did you mean: 
gregstahl
New Contributor III
‎01-09-2015 11:33 AM

SIP to PRI- outbound call fails

TA912 just doing SIP<=>PRI.  Carrier has Metaswitch, PRI terminates to a Cisco 2921.  Inbound calling (to the 2921) works great, outbound fails.

SIP Stack- Verbose and ISDN- Verbose debug attached.

Scrubbed config attached.

Any help would be greatly appreciated.

Thanks,

Greg

CPH_Conf.txt.zip
CPH_Adtran_debug.zip
0 Kudos
Reply
3 Replies
gregstahl
New Contributor III
‎01-09-2015 12:03 PM

Re: SIP to PRI- outbound call fails

Development---  I found what may be causing this...I copied my config from another unit in our network, and that unit has the following:

match ani "$" substitute "3157143110" name "ANI Sub"

That DID is not in the PBX object range in my Metaswitch, so that may be why it is failing.   I'm going to remove it and test again when I get another maintenance window.

Greg

0 Kudos
Accept as Solution Reply
gregstahl
New Contributor III
‎01-11-2015 09:38 AM

Re: SIP to PRI- outbound call fails

Well, I removed the ani sub string and outbound calls still fail.  I'm at a loss.  I ran a new sip stack-verbose and isdn- verbose debug and attached it here.

0 Kudos
Accept as Solution Reply
gregstahl
New Contributor III
‎01-11-2015 09:43 AM

Re: SIP to PRI- outbound call fails

22:39:42.888 SIP.STACK DEBUG  MESSAGE  AddrUrlEncode - Encoding Url Address. hSipUrl 0x2842628, hPool 0x27c4f10, hPage 42098080
22:39:42.889 SIP.STACK DEBUG  MESSAGE  RvSipCSeqHeaderEncode - Encoding CSeq header. hHeader 0x28423f8, hPool 0x27c4f10, hPage 42098080
22:39:42.890 SIP.STACK DEBUG  MESSAGE  RvSipViaHeaderEncode - Via header 0x2842420 was encoded successfully.
22:39:42.890 SIP.STACK DEBUG  MESSAGE  RvSipAddrEncode - Encoding Address. hSipAddr 0x28427f0, hPool 0x27c4f10, hPage 42098080
22:39:42.891 SIP.STACK DEBUG  MESSAGE  AddrUrlEncode - Encoding Url Address. hSipUrl 0x28427f0, hPool 0x27c4f10, hPage 42098080

22:39:42.892 SIP.STACK DEBUG  TRANSMITTER  TransmitterMsgToSendListAddElement - Transmitter 0x2ad22a8, adding page 0x2825da0

22:39:42.892 SIP.STACK DEBUG  RPOOL    RPOOL_FreePage - (pool=0x27c4f10,element=0x28422e0) (MessagePool)
22:39:42.893 SIP.STACK DEBUG  TRANSPORTSipTransportUdpSendMessage - sock 28: Sending UDP message. 162.211.172.51:5060->173.245.145.8:5060, size=641

22:39:42.894 SIP.STACK MSGSUM  Tx: ACK sip:2612412@173.245.145.8:5060;transport=UDP SIP/2.0

22:39:42.894 SIP.STACK DEBUG  TRANSPORTTransportCallbackMsgToSendEv: Application did not register to call back, default bSendMsg = 1
22:39:42.895 SIP.STACK DEBUG  TRANSPORTTransportCallbackBufferToSend: Application did not register to call back, default *bDiscardBuffer=FALSE

22:39:42.896 SIP.STACK DEBUG  TRANSMITTER  TransmitterControlTransmitMessage - pTrx=0x2ad22a8: A message was successfully sent over UDP.

22:39:42.897 SIP.STACK DEBUG  RPOOL    RPOOL_FreePage - (pool=0x27c4f10,element=0x28321a0) (MessagePool)

22:39:42.898 SIP.STACK DEBUG  TRANSMITTER  TransmitterChangeState - transmitter 0x2ad22a8 state changed: Ready For Sending->Msg Sent, (reason = Undefined)

22:39:42.898 SIP.STACK DEBUG  TRANSMITTER  TransmitterCallbackStateChangeEv: Transmitter 0x2ad22a8 - Before callback

22:39:42.899 SIP.STACK DEBUG  TRANSACTION  UDPTimersDecide - Transaction 0x2ae0e98: Setting timers

22:39:42.900 SIP.STACK DEBUG  TIMER    RvTimerStart: event allocated(tqueue=29641ac; timer=2ae0f80; event=2964898)

22:39:42.900 SIP.STACK DEBUG  TRANSACTION  TransactionTimerSetTimers - Transaction 0x2ae0e98: timer was set to 32000 milliseconds

22:39:42.901 SIP.STACK DEBUG  TRANSMITTER  TransmitterCallbackStateChangeEv: Transmitter 0x2ad22a8,After callback

22:39:42.901 SIP.STACK DEBUG  TRANSACTION  TransactionCallbackStateChangedEv: Transc 0x2ae0e98, Before callback

22:39:42.902 SIP.STACK DEBUG  TRANSACTION  TransactionCallbackStateChangedEv: Transc 0x2ae0e98,After callback

22:39:42.902 SIP.STACK DEBUG  CALL     CallLegRemoveTranscFromList - call-leg 0x2b05358 remove transc 0x2ae0e98 from transc list

22:39:42.903 SIP.STACK DEBUG  TRANSACTION  SipTransactionDetachOwner - transc 0x2ae0e98, calling  TransactionNoOwner()

22:39:42.904 SIP.STACK DEBUG  RPOOL    RPOOL_Append - (pool=0x28b62f0,element=0x28dce98,size=57,consecutiveMemory=0,*AllocationOffset=0x3fe) new block appended (GeneralPool)

22:39:42.904 SIP.STACK DEBUG  TRANSACTION  SipTransactionDetachOwner - Transaction 0x2ae0e98: Detached successfully

22:39:42.905 SIP.STACK DEBUG  CALL     CallLegCallbackChangeCallStateEv - call-leg 0x2b05358, Before callback
22:39:42.906 SIP.STACK DEBUG  CALL     CallLegCallbackChangeCallStateEv - call-leg 0x2b05358 After callback
22:39:42.906 SIP.STACK DEBUG  CALL     CallLegTerminateAllTransc - Call-leg 0x2b05358 - terminating all its transactions.
22:39:42.907 SIP.STACK DEBUG  CALL     CallLegTerminateIfPossible - Send Call-leg 0x2b05358 to the event queue for termination
22:39:42.908 SIP.STACK DEBUG  TRANSPORTSipTransportSendObjectEvent - pObj=0x2b05358,pEventInfo=0x2b0535c,eNum=19,bInternal=1
22:39:42.909 SIP.STACK DEBUG  TRANSPORTTransportProcessingQueueTailEvent - INTERNAL_EVENT ev=0x29b05c0: Call-Leg 0x2b05358: Terminated
22:39:42.909 SIP.STACK DEBUG  TRANSPORTSipTransportSendObjectEvent - ev 0x29b05c0 sent. (Call-Leg 0x2b05358: Terminated)

22:39:42.910 SIP.STACK DEBUG  TRANSACTION  TransactionCallbackStateChangedEv: Transc 0x2ae0e98,After callback

22:39:42.910 SIP.STACK DEBUG  MSGBUILDER   TransportCallbackMsgRcvdEv: Msg 0x2842920 After callback

22:39:42.911 SIP.STACK DEBUG  RPOOL    RPOOL_FreePage - (pool=0x27c4f10,element=0x2842900) (MessagePool)
22:39:42.912 SIP.STACK DEBUG  TRANSPORTTransportProcessingQueueDispatchEvents - INTERNAL_EVENT ev:0x29b05c0, (Call-Leg 0x2b05358: Terminated)
22:39:42.912 SIP.STACK DEBUG  CALL     TerminateCallegEventHandler - Call-leg 0x2b05358 is out of termination queue...
22:39:42.913 SIP.STACK DEBUG  CALL     CallLegCallbackChangeCallStateEv - call-leg 0x2b05358, Before callback
22:39:42.913 SIP.STACK DEBUG  CALL     CallLegCallbackChangeCallStateEv - call-leg 0x2b05358 After callback
22:39:42.914 SIP.STACK DEBUG  CALL     CallLegDestruct - Call-leg 0x2b05358 destructing...
22:39:42.914 SIP.STACK DEBUG  CALL     CallLegForkingDestructAckMsgParams - call-leg 0x2b05358 - no ACK message to destruct
22:39:42.915 SIP.STACK DEBUG  CALL     CallLegForkingDestructAckMsgParams - call-leg 0x2b05358 - no ACK transmitter to destruct
22:39:42.916 SIP.STACK DEBUG  CALL     CallLegForkingDestructAckMsgParams - call-leg 0x2b05358 - no ACK transmitter page to destruct
22:39:42.916 SIP.STACK DEBUG  RPOOL    RPOOL_FreePage - (pool=0x28b62f0,element=0x28dca78) (GeneralPool)
22:39:42.917 SIP.STACK DEBUG  RPOOL    RPOOL_FreePage - (pool=0x29444d0,element=0x2947608) (ElementPool)
22:39:42.919 SIP.STACK WARN   CALL     CallLegLock - Call 0x2b05358: RLIST_IsElementVacant returned RV_TRUE
22:39:42.919 SIP.STACK WARN   CALL     CallLegLock - Call 0x2b05358: RLIST_IsElementVacant returned RV_TRUE
22:39:42.921 ISDN.EP PRI  1  Call to '2612412' cleared from this end

22:39:42.922 ISDN.CC_MSG PRI  1  Host>>CC: 00 0013 DISC_REQ

22:39:42.922 ISDN.CC_IE  PRI  1 ie: 00 08 04 00 82 00 95

22:39:42.940 ISDN.L2_FMT PRI  1  ==============================================

22:39:42.940 ISDN.L2_MSG PRI  1  T 02 01 32 2A 08 02 80 05 45 08 02 82 95

22:39:42.941 ISDN.L2_FMT PRI  1Sapi:00 C/R:C Tei:00 INFO Ns:25  Nr:21  P:0
22:39:42.941 ISDN.L2_FMT PRI  1Prot:08  CRL:2  CRV:8005
22:39:42.941 ISDN.L2_FMT PRI  1M - 45 DISCONNECT 
22:39:42.941 ISDN.L2_FMT PRI  1 IE - 08 CAUSE           Len=2
22:39:42.942 ISDN.L2_FMT PRI  1      82 Location:LN
22:39:42.942 ISDN.L2_FMT PRI  1      95 Cause:21 (CALL_REJECTED)

22:39:42.950 ISDN.L2_FMT PRI  1  ==============================================

22:39:42.951 ISDN.L2_MSG PRI  1  R 02 01 01 34

22:39:42.951 ISDN.L2_FMT PRI  1Sapi:00 C/R:C Tei:00 Ctl:RRNr:26  P/F:0

22:39:42.989 ISDN.L2_FMT PRI  1  ==============================================

22:39:42.989 ISDN.L2_MSG PRI  1  R 00 01 2A 34 08 02 00 05 4D

22:39:42.989 ISDN.L2_FMT PRI  1Sapi:00 C/R:R Tei:00 INFO Ns:21  Nr:26  P:0
22:39:42.990 ISDN.L2_FMT PRI  1Prot:08  CRL:2  CRV:0005
22:39:42.990 ISDN.L2_FMT PRI  1M - 4D RELEASE

22:39:42.990 ISDN.L2_FMT PRI  1  ==============================================

22:39:42.991 ISDN.L2_MSG PRI  1  T 00 01 01 2C

22:39:42.991 ISDN.L2_FMT PRI  1Sapi:00 C/R:R Tei:00 Ctl:RRNr:22  P/F:0

22:39:43.003 ISDN.L2_FMT PRI  1  ==============================================

22:39:43.003 ISDN.L2_MSG PRI  1  T 02 01 34 2C 08 02 80 05 5A

22:39:43.003 ISDN.L2_FMT PRI  1Sapi:00 C/R:C Tei:00 INFO Ns:26  Nr:22  P:0
22:39:43.004 ISDN.L2_FMT PRI  1Prot:08  CRL:2  CRV:8005
22:39:43.004 ISDN.L2_FMT PRI  1M - 5A RELEASE_CMP

22:39:43.005 ISDN.CC_MSG PRI  1  CC>>Host: 02 0013 CLEAR_CONF

22:39:43.006 ISDN.RES_MGR Releasing inbound channel, called number 2612412.

22:39:43.011 ISDN.L2_FMT PRI  1  ==============================================

22:39:43.012 ISDN.L2_MSG PRI  1  R 02 01 01 36

22:39:43.012 ISDN.L2_FMT PRI  1Sapi:00 C/R:C Tei:00 Ctl:RRNr:27  P/F:0
22:39:48.315 SIP.STACK DEBUG  TIMER    RvTimerQueueService: timer expired(tqueue=29641ac; event=29647a8)
22:39:48.316 SIP.STACK DEBUG  TRANSPORTTransportMultiThreadTimerEventHandler - Allocating timer expired event
22:39:48.316 SIP.STACK DEBUG  TRANSPORTTransportProcessingQueueTailEvent - TIMER_EXPIRED_EVENT 0x29b0600
22:39:48.317 SIP.STACK DEBUG  TRANSPORTTransportProcessingQueueDispatchEvents - TIMER_EXPIRED_EVENT 0x29b0600
22:39:48.318 SIP.STACK DEBUG  TIMER    RvTimerQueueService: timer expired(tqueue=29641ac; event=29647a8)

22:39:48.318 SIP.STACK DEBUG  TRANSACTION  TransactionTimerHandleMainTimerTimeout - Transaction 0x2ae06d8: timer expired (transc state=Server General Final Response Sent)

22:39:48.319 SIP.STACK DEBUG  TRANSACTION  TransactionTerminate - Transaction 0x2ae06d8: Termination called

22:39:48.319 SIP.STACK DEBUG  TRANSACTION  TransactionTransportDetachAllConnections - Transaction 0x2ae06d8: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)

22:39:48.320 SIP.STACK DEBUG  TRANSPORTSipTransportSendObjectEvent - pObj=0x2ae06d8,pEventInfo=0x2ae06d8,eNum=3,bInternal=1
22:39:48.321 SIP.STACK DEBUG  TRANSPORTTransportProcessingQueueTailEvent - INTERNAL_EVENT ev=0x29b0640: Transaction 0x2ae06d8: Terminated
22:39:48.321 SIP.STACK DEBUG  TRANSPORTSipTransportSendObjectEvent - ev 0x29b0640 sent. (Transaction 0x2ae06d8: Terminated)
22:39:48.322 SIP.STACK DEBUG  TRANSPORTTransportProcessingQueueDispatchEvents - INTERNAL_EVENT ev:0x29b0640, (Transaction 0x2ae06d8: Terminated)

22:39:48.323 SIP.STACK DEBUG  TRANSACTION  TransactionCallbackStateChangedEv: Transc 0x2ae06d8, Before callback

22:39:48.324 SIP.STACK DEBUG  TRANSACTION  TransactionCallbackStateChangedEv: Transc 0x2ae06d8,After callback

22:39:48.324 SIP.STACK DEBUG  TRANSACTION  TransactionDestruct - Transaction 0x2ae06d8: start to destruct transaction

22:39:48.325 SIP.STACK DEBUG  TRANSACTION  TransactionTransportDetachAllConnections - Transaction 0x2ae06d8: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)

22:39:48.326 SIP.STACK DEBUG  TRANSMITTER  TransmitterDestruct - transmitter 0x2ad1af8 destructing...

22:39:48.326 SIP.STACK DEBUG  RPOOL    RPOOL_FreePage - (pool=0x27c4f10,element=0x2837d80) (MessagePool)
22:39:48.327 SIP.STACK DEBUG  RPOOL    RPOOL_FreePage - (pool=0x28b62f0,element=0x28d9d18) (GeneralPool)

22:39:53.230 ISDN.L2_FMT PRI  1  ==============================================

22:39:53.231 ISDN.L2_MSG PRI  1  T 02 01 01 2D

22:39:53.231 ISDN.L2_FMT PRI  1Sapi:00 C/R:C Tei:00 Ctl:RRNr:22  P/F:1

22:39:53.238 ISDN.L2_FMT PRI  1  ==============================================

22:39:53.239 ISDN.L2_MSG PRI  1  R 02 01 01 37

22:39:53.239 ISDN.L2_FMT PRI  1Sapi:00 C/R:C Tei:00 Ctl:RRNr:27  P/F:1
22:40:00.225 SIP.STACK DEBUG  SELECT   Occured event: fd=28,event=Read ,error=0
22:40:00.225 SIP.STACK DEBUG  TRANSPORTTransportMgrAllocateRcvBuffer - Successfully allocated buffer 0x2a61560
22:40:00.226 SIP.STACK DEBUG  TRANSPORTTransportUdpEventCallback - sock 28: Recv new UDP message. 162.211.172.51:5060<-173.245.145.8:5060, size=714

22:40:00.227 SIP.STACK MSGSUM  Rx: OPTIONS sip:metaswitch@162.211.172.51:5060;transport=udp SIP/2.0 (with SDP)

22:40:00.227 SIP.STACK DEBUG  TRANSPORTTransportProcessingQueueTailEvent - MESSAGE_RCVD_EVENT 0x29b0680, buffer 0x2a61560
22:40:00.228 SIP.STACK DEBUG  TRANSPORTTransportProcessingQueueDispatchEvents - MESSAGE_RCVD_EVENT 0x29b0680, buffer 0x2a61560
22:40:00.229 SIP.STACK DEBUG  TRANSPORTTransportCallbackBufferReceived: Local Addrs (162.211.172.51:5060,UDP), Remote Addrs (173.245.145.8:5060,UDP), hConn=0x0, buffLen=714 Before callback
0 Kudos
Accept as Solution Reply