I am running an TA908e with the following layout
3CX -> Yeastar TE100 -> TA908e -> SIP Trunks
I can call into the 3CX box using an external number. If I pick up an extension registered to 3CX and dial an outbound number, I get an error on the ISDN/PRI debug below.
06:17:53.295 ISDN.L2_FMT PRI 1 ==============================================
06:17:53.295 ISDN.L2_FMT PRI 1 R Sapi:00 C/R:R Tei:00 INFO Ns:50 Nr:52 P:0
06:17:53.295 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:0003
06:17:53.295 ISDN.L2_FMT PRI 1 M - 05 SETUP
06:17:53.296 ISDN.L2_FMT PRI 1 IE - 04 BEARER CAPABILITY Len=3
06:17:53.296 ISDN.L2_FMT PRI 1 80 Xfer Cap.:SPEECH
06:17:53.296 ISDN.L2_FMT PRI 1 90 Xfer Rate:64k
06:17:53.296 ISDN.L2_FMT PRI 1 A3 Layer 1:G.711 A-Law
06:17:53.296 ISDN.L2_FMT PRI 1 IE - 18 CHANNEL ID Len=3
06:17:53.296 ISDN.L2_FMT PRI 1 A1 Primary Rate
06:17:53.296 ISDN.L2_FMT PRI 1 Intfc ID:IMPLICIT
06:17:53.296 ISDN.L2_FMT PRI 1 Pref/Excl:PREFERRED
06:17:53.296 ISDN.L2_FMT PRI 1 D-Chan Indicated:NO
06:17:53.297 ISDN.L2_FMT PRI 1 Chan. Sel:FOLLOWS
06:17:53.297 ISDN.L2_FMT PRI 1 83 Numb/Map:NUMBER
06:17:53.297 ISDN.L2_FMT PRI 1 81 Channel:1
06:17:53.297 ISDN.L2_FMT PRI 1 IE - 1E PROGRESS INDICATOR Len=2
06:17:53.297 ISDN.L2_FMT PRI 1 80 Location:U
06:17:53.297 ISDN.L2_FMT PRI 1 83 Description:ORIG. NOT ISDN
06:17:53.297 ISDN.L2_FMT PRI 1 IE - 28 DISPLAY Len=11
06:17:53.297 ISDN.L2_FMT PRI 1 B1 Associated Information:INCLUDED
06:17:53.297 ISDN.L2_FMT PRI 1 Display Type:CALLING PARTY NAME
06:17:53.298 ISDN.L2_FMT PRI 1 3615612122
06:17:53.298 ISDN.L2_FMT PRI 1 IE - 6C CALLING PARTY # Len=12
06:17:53.298 ISDN.L2_FMT PRI 1 28 Numb. Type:NATIONAL
06:17:53.298 ISDN.L2_FMT PRI 1 Numb. Plan:NATIONAL
06:17:53.298 ISDN.L2_FMT PRI 1 80 Presentation:ALLOWED
06:17:53.298 ISDN.L2_FMT PRI 1 Screening:USER PROVIDED
06:17:53.298 ISDN.L2_FMT PRI 1 Ph.# 3615612122
06:17:53.298 ISDN.L2_FMT PRI 1 IE - 70 CALLED PARTY # Len=11
06:17:53.299 ISDN.L2_FMT PRI 1 A0 Numb. Type:NATIONAL
06:17:53.299 ISDN.L2_FMT PRI 1 Numb. Plan:UNKNOWN
06:17:53.299 ISDN.L2_FMT PRI 1 Ph.# 9563690060
06:17:53.300 ISDN.L2_FMT PRI 1 ==============================================
06:17:53.300 ISDN.L2_FMT PRI 1 T Sapi:00 C/R:C Tei:00 INFO Ns:52 Nr:51 P:0
06:17:53.300 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:8003
06:17:53.301 ISDN.L2_FMT PRI 1 M - 02 CALL_PROC
06:17:53.301 ISDN.L2_FMT PRI 1 IE - 18 CHANNEL ID Len=3
06:17:53.301 ISDN.L2_FMT PRI 1 A9 Primary Rate
06:17:53.301 ISDN.L2_FMT PRI 1 Intfc ID:IMPLICIT
06:17:53.301 ISDN.L2_FMT PRI 1 Pref/Excl:EXCLUSIVE
06:17:53.301 ISDN.L2_FMT PRI 1 D-Chan Indicated:NO
06:17:53.301 ISDN.L2_FMT PRI 1 Chan. Sel:FOLLOWS
06:17:53.301 ISDN.L2_FMT PRI 1 83 Numb/Map:NUMBER
06:17:53.301 ISDN.L2_FMT PRI 1 81 Channel:1
06:17:53.310 ISDN.L2_FMT PRI 1 ==============================================
06:17:53.310 ISDN.L2_FMT PRI 1 T Sapi:00 C/R:C Tei:00 INFO Ns:53 Nr:51 P:0
06:17:53.310 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:8003
06:17:53.311 ISDN.L2_FMT PRI 1 M - 45 DISCONNECT
06:17:53.311 ISDN.L2_FMT PRI 1 IE - 08 CAUSE Len=2
06:17:53.311 ISDN.L2_FMT PRI 1 82 Location:LN
06:17:53.311 ISDN.L2_FMT PRI 1 A9 Cause:41 (TEMPORARY_FAILURE)
06:17:53.410 ISDN.L2_FMT PRI 1 ==============================================
06:17:53.410 ISDN.L2_FMT PRI 1 R Sapi:00 C/R:R Tei:00 INFO Ns:51 Nr:54 P:0
06:17:53.410 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:0003
06:17:53.410 ISDN.L2_FMT PRI 1 M - 4D RELEASE
06:17:53.411 ISDN.L2_FMT PRI 1 IE - 08 CAUSE Len=2
06:17:53.411 ISDN.L2_FMT PRI 1 81 Location:LPN
06:17:53.411 ISDN.L2_FMT PRI 1 A9 Cause:41 (TEMPORARY_FAILURE)
06:17:53.411 ISDN.L2_FMT PRI 1 ==============================================
06:17:53.411 ISDN.L2_FMT PRI 1 T Sapi:00 C/R:C Tei:00 INFO Ns:54 Nr:52 P:0
06:17:53.412 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:8003
06:17:53.412 ISDN.L2_FMT PRI 1 M - 5A RELEASE_CMP
Not sure what's happening since calls in the other direction are working properly.
I am running firmware R12.3.4.E.
IT was working with an older version 10.3.x but not I cannot download that old version,.
Any help is appreciated.
Thomas,
Can you please enter the following debug commands and then place the call again.
debug sip stack messages
debug sip cldu
debug voice verbose
debug isdn l2-formatted
that is lowercase L for the l2 command
then past the output in a reply.
Thanks!
09:27:58.402 SIP.STACK DEBUG CALL CallLegCallbackMsgToSendEv - call-leg 0x52d06c0 After callback
09:27:58.402 SIP.STACK DEBUG TRANSACTION TransactionCallbackMsgToSendEv: Transc 0x5279a58,After callback (rv=0)
09:27:58.402 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x5279a58: Copied the top via header from message into the transc object.
09:27:58.403 SIP.STACK DEBUG TRANSACTION TransactionMgrHashInsert - Transc=0x5279a58 was inserted to hash
09:27:58.403 SIP.STACK DEBUG TRANSACTION TransactionTransportSendMsg - Transaction 0x5279a58 is about to send message 0x3ce2310. msgType = Request Sent, bResolveAddress = 1
09:27:58.403 SIP.STACK DEBUG TRANSMITTER CheckForOutboundAddress - returning IP String 75.98.50.46:5060;transport=UDP
09:27:58.403 SIP.STACK DEBUG TRANSMITTER GetRequestAddressFromMsg - trx=0x526d420: outbound address will be used
09:27:58.403 SIP.STACK DEBUG TRANSMITTER TransmitterDestIdentifyDestAddress - pTrx=0x211c9cf: address was not resolved, Will try to discover address
09:27:58.404 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d420 state changed: Idle->Resolving Addr, (reason = Undefined)
09:27:58.404 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420 - Before callback
09:27:58.404 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420,After callback
09:27:58.404 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d420 state changed: Resolving Addr->Final Dest Resolved, (reason = Undefined)
09:27:58.404 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420 - Before callback
09:27:58.405 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc 0x5279a58 - Destination address is: ip=75.98.50.46, port=5060, transport=UDP, address type=IPv4
09:27:58.405 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc=0x5279a58, hMsg=0x3ce2310, Before callback
09:27:58.405 SIP.STACK DEBUG CALL CallLegCallbackFinalDestResolvedEv: CallLeg=0x52d06c0, Transc=0x5279a58, appTransc=0x0, hMsg=0x3ce2310, Application did not register to callback
09:27:58.405 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc 0x5279a58,After callback (rv=0)
09:27:58.406 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420,After callback
09:27:58.406 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d420 state changed: Final Dest Resolved->Ready For Sending, (reason = Undefined)
09:27:58.406 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420 - Before callback
09:27:58.406 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x5279a58: Copied the top via header from message into the transc object.
09:27:58.407 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420,After callback
09:27:58.407 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce6030)=0 (MessagePool)
09:27:58.407 SIP.STACK DEBUG MESSAGE RvSipMsgEncode - Got new page 0x3ce6030 on pool 0x3b9f010. hSipMsg is 0x3ce2310
09:27:58.407 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce24e0, hPool 0x3b9f010, hPage 63856688
09:27:58.407 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce24e0, hPool 0x3b9f010, hPage 63856688
09:27:58.408 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce26b0, hPool 0x3b9f010, hPage 63856688
09:27:58.408 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce26b0, hPool 0x3b9f010, hPage 63856688
09:27:58.408 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce27b8, hPool 0x3b9f010, hPage 63856688
09:27:58.408 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce27b8, hPool 0x3b9f010, hPage 63856688
09:27:58.409 SIP.STACK DEBUG MESSAGE RvSipCSeqHeaderEncode - Encoding CSeq header. hHeader 0x3ce2588, hPool 0x3b9f010, hPage 63856688
09:27:58.409 SIP.STACK DEBUG MESSAGE RvSipViaHeaderEncode - Via header 0x3ce25b0 was encoded successfully.
09:27:58.409 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce3bf0, hPool 0x3b9f010, hPage 63856688
09:27:58.410 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce3bf0, hPool 0x3b9f010, hPage 63856688
09:27:58.410 SIP.STACK DEBUG TRANSMITTER TransmitterMsgToSendListAddElement - Transmitter 0x526d420, adding page 0x3ce6030
09:27:58.410 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce22f0) (MessagePool)
09:27:58.410 SIP.STACK DEBUG TRANSPORT SipTransportUdpSendMessage - sock 27: Sending UDP message. 172.16.30.40:5060->75.98.50.46:5060, size=978
09:27:58.411 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgToSendEv: Application did not register to call back, default bSendMsg = 1
09:27:58.411 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferToSend: Application did not register to call back, default *bDiscardBuffer=FALSE
09:27:58.411 SIP.STACK DEBUG TRANSMITTER TransmitterControlTransmitMessage - pTrx=0x526d420: A message was successfully sent over UDP.
09:27:58.412 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d420 state changed: Ready For Sending->Msg Sent, (reason = Undefined)
09:27:58.412 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420 - Before callback
09:27:58.412 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x5279a58: Setting timers
09:27:58.412 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x5279a58: state=Client Invite Calling, Decisions: (*bSetMainTimer=1, *mainTimerInterval=500, *bSetLongReqestTimer=0, *longTimerInterval=0
09:27:58.412 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=5279b48; event=3f5f0c8)
09:27:58.413 SIP.STACK DEBUG TRANSACTION TransactionTimerSetTimers - Transaction 0x5279a58: timer was set to 500 milliseconds
09:27:58.413 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420,After callback
09:27:58.413 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279a58, Before callback
09:27:58.413 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279a58,After callback
09:27:58.413 SIP.STACK DEBUG TRANSACTION SipTransactionRequest - Transaction 0x5279a58: Request was sent successfully
09:27:58.414 SIP.STACK DEBUG CALL CallLegCallbackChangeCallStateEv - call-leg 0x52d06c0, Before callback
09:27:58.414 SIP.CLDU Cldu::CallLegStateChangedEv: (0x52d06c0)->Inviting
09:27:58.414 TM.T01 03 Delivering call-leg -> Inviting
09:27:58.414 SIP.STACK DEBUG CALL CallLegCallbackChangeCallStateEv - call-leg 0x52d06c0 After callback
09:27:58.414 TM.T01 03 Delivering sent: INVITE
09:27:58.415 SB.CALL 11 Delivering Called the deliverResponse routine from Delivering
09:27:58.415 SB.CALL 11 Delivering DeliverResponse(accept) sent from T01 to T02
09:27:58.415 TA.T02 23 TAConnectWaitIn deliverResponse event accepted
09:27:58.416 TA.T02 23 TAConnectWaitIn ERROR! deliverResponse ignored
09:27:58 SB.CallStructObserver 11 Created
09:27:58.470 SIP.STACK DEBUG SELECT Occured event: fd=27,event=Read ,error=0
09:27:58.470 SIP.STACK DEBUG TRANSPORT TransportMgrAllocateRcvBuffer - Successfully allocated buffer 0x49460e8
09:27:58.470 SIP.STACK DEBUG TRANSPORT TransportUdpEventCallback - sock 27: Recv new UDP message. 172.16.30.40:5060<-75.98.50.46:5060, size=405
09:27:58.471 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - MESSAGE_RCVD_EVENT 0x4017d28, buffer 0x49460e8
09:27:58.471 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - MESSAGE_RCVD_EVENT 0x4017d28, buffer 0x49460e8
09:27:58.471 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=405 Before callback
09:27:58.471 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: bDiscardBuffer=FALSE, Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=405 After callback
09:27:58.472 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce1cd0)=0 (MessagePool)
09:27:58.472 SIP.STACK DEBUG MESSAGE RvSipMsgConstruct - Got a new page. hPage is 0x3ce1cd0.
09:27:58.473 SIP.STACK DEBUG MESSAGE RvSipViaHeaderSetCompactForm - Setting compact form of Header 0x3ce1d50 to 0
09:27:58.473 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3ce1e20 to 0
09:27:58.473 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3ce1f20 to 0
09:27:58.474 SIP.STACK DEBUG MESSAGE RvSipMsgSetContentLengthCompactForm - Setting compact form of Content-Length for hMsg 0x3ce1cf0 to 0
09:27:58.474 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3ce1cf0: Before callback
09:27:58.475 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce1f58
09:27:58.475 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce1e60
09:27:58.475 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3ce1cf0: After callback, bProcessMsg = 1
09:27:58.475 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3ce1cf0 Before callback (bsAction=Continue)
09:27:58.475 SIP.STACK DEBUG TRANSACTION HandleIncomingResponseMsg - A response msg 0x3ce1cf0- starting to process...
09:27:58.476 SIP.STACK DEBUG TRANSACTION HashKeyMethodsAreEqual - Methods are equal (INVITE)
09:27:58.476 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x5279a58, Before callback
09:27:58.476 SIP.STACK DEBUG CALL CallLegMsgEvMsgRcvdHandler - Call-Leg 0x52d06c0 (htrans=0x5279a58,hMsg=0x3ce1cf0) - received a message
09:27:58.476 SIP.STACK DEBUG CALL CallLegCallbackMsgReceivedEv: CallLeg 0x52d06c0, Before callback
09:27:58.477 SIP.CLDU Incoming message received from 75.98.50.46:5060 via UDP
09:27:58.477 TM.T01 03 Delivering rcvd SIP call-leg response: 100 Trying
09:27:58.477 TM.T01 03 Delivering rcvd: Provisional Response 100
09:27:58.477 SIP.STACK DEBUG CALL CallLegCallbackMsgReceivedEv - call-leg 0x52d06c0 After callback (rv=0)
09:27:58.477 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x5279a58,After callback (rv=0)
09:27:58.478 SIP.STACK DEBUG TRANSACTION TransactionTimerMainTimerRelease - Transaction 0x5279a58: Timer 0x5279b48 was released
09:27:58.478 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279a58, Before callback
09:27:58.478 SIP.STACK DEBUG TRANSACTION RvSipTransactionGetReceivedMsg - transc= 0x5279a58 returned handle= 0x3ce1cf0
09:27:58.478 SIP.STACK DEBUG CALL CallLegCallbackChangeCallStateEv - call-leg 0x52d06c0, Before callback
09:27:58.478 SIP.CLDU Cldu::CallLegStateChangedEv: (0x52d06c0)->Proceeding
09:27:58.479 TM.T01 03 Delivering call-leg -> Proceeding
09:27:58.479 SIP.STACK DEBUG CALL CallLegCallbackChangeCallStateEv - call-leg 0x52d06c0 After callback
09:27:58.479 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279a58,After callback
09:27:58.479 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3ce1cf0 After callback
09:27:58.479 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce1cd0) (MessagePool)
09:27:58.537 SIP.STACK DEBUG SELECT Occured event: fd=27,event=Read ,error=0
09:27:58.537 SIP.STACK DEBUG TRANSPORT TransportMgrAllocateRcvBuffer - Successfully allocated buffer 0x494e0e8
09:27:58.537 SIP.STACK DEBUG TRANSPORT TransportUdpEventCallback - sock 27: Recv new UDP message. 172.16.30.40:5060<-75.98.50.46:5060, size=758
09:27:58.538 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - MESSAGE_RCVD_EVENT 0x4017d70, buffer 0x494e0e8
09:27:58.538 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - MESSAGE_RCVD_EVENT 0x4017d70, buffer 0x494e0e8
09:27:58.538 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=758 Before callback
09:27:58.539 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: bDiscardBuffer=FALSE, Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=758 After callback
09:27:58.539 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce4dd0)=0 (MessagePool)
09:27:58.539 SIP.STACK DEBUG MESSAGE RvSipMsgConstruct - Got a new page. hPage is 0x3ce4dd0.
09:27:58.540 SIP.STACK DEBUG MESSAGE RvSipViaHeaderSetCompactForm - Setting compact form of Header 0x3ce4e50 to 0
09:27:58.540 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3ce4f20 to 0
09:27:58.540 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3ce5020 to 0
09:27:58.541 SIP.STACK DEBUG MESSAGE RvSipContactHeaderSetCompactForm - Setting compact form of hHeader 0x3ce51c0 to 0
09:27:58.541 SIP.STACK DEBUG MESSAGE RvSipContentTypeHeaderSetCompactForm - Setting compact form of hHeader 0x3ce5330 to 0
09:27:58.542 SIP.STACK DEBUG MESSAGE RvSipMsgSetContentLengthCompactForm - Setting compact form of Content-Length for hMsg 0x3ce4df0 to 0
09:27:58.542 SIP.STACK DEBUG RPOOL RPOOL_Append - (pool=0x3b9f010,element=0x3ce4dd0,size=238,consecutiveMemory=0,*AllocationOffset=0x594) new block appended (MessagePool)
09:27:58.542 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3ce4df0: Before callback
09:27:58.543 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce5058
09:27:58.543 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce4f60
09:27:58.543 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3ce4df0: After callback, bProcessMsg = 1
09:27:58.543 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3ce4df0 Before callback (bsAction=Continue)
09:27:58.543 SIP.STACK DEBUG TRANSACTION HandleIncomingResponseMsg - A response msg 0x3ce4df0- starting to process...
09:27:58.544 SIP.STACK DEBUG TRANSACTION HashKeyMethodsAreEqual - Methods are equal (INVITE)
09:27:58.544 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x5279a58, Before callback
09:27:58.544 SIP.STACK DEBUG CALL CallLegMsgEvMsgRcvdHandler - Call-Leg 0x52d06c0 (htrans=0x5279a58,hMsg=0x3ce4df0) - received a message
09:27:58.544 SIP.STACK DEBUG CALL CallLegCallbackMsgReceivedEv: CallLeg 0x52d06c0, Before callback
09:27:58.545 SIP.CLDU Incoming message received from 75.98.50.46:5060 via UDP
09:27:58.545 TM.T01 03 Delivering rcvd SIP call-leg response: 200 OK
09:27:58.545 SIP.STACK DEBUG CALL CallLegCallbackMsgReceivedEv - call-leg 0x52d06c0 After callback (rv=0)
09:27:58.545 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3f14010,element=0x3f15698) (ElementPool)
09:27:58.546 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3f14010,size=0,*newRpoolElem=0x3f157b8)=0 (ElementPool)
09:27:58.546 SIP.STACK DEBUG CALL CallLegRouteListInitialize - Call-leg 0x52d06c0 - Route list initialized
09:27:58.546 SIP.STACK DEBUG CALL LoadFromInviteResponseRcvdMsg - Call-Leg 0x52d06c0 - Route list was built from 2xx response
09:27:58.546 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x5279a58,After callback (rv=0)
09:27:58.546 SIP.STACK DEBUG TRANSACTION UpdateToHeader: transc 0x5279a58 - copy To header with new to-tag from msg (pool=0x3dde010 page=0x3e07130)
09:27:58.547 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279a58, Before callback
09:27:58.547 SIP.STACK DEBUG TRANSACTION RvSipTransactionGetReceivedMsg - transc= 0x5279a58 returned handle= 0x3ce4df0
09:27:58.547 SIP.STACK DEBUG CALL CallLegCallbackChangeCallStateEv - call-leg 0x52d06c0, Before callback
09:27:58.547 SIP.CLDU Cldu::CallLegStateChangedEv: (0x52d06c0)->RemoteAccepted
09:27:58.548 TM.T01 03 Delivering call-leg -> RemoteAccepted
09:27:58.548 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce5218
09:27:58.548 TM.T01 03 Delivering State change >> Delivering->SipTM_Answering
09:27:58.549 SIP.STACK DEBUG CALL RvSipCallLegGetCallId - getting call id for call-leg 0x52d06c0
09:27:58.549 TM.T01 03 SipTM_Answering sent: TA->Connect
09:27:58.549 SIP.STACK DEBUG CALL CallLegCallbackChangeCallStateEv - call-leg 0x52d06c0 After callback
09:27:58.549 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279a58,After callback
09:27:58.550 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3ce4df0 After callback
09:27:58.550 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce4dd0) (MessagePool)
09:27:58.550 TA.T01 03 TAOutGoing rcvd: connect from TM
09:27:58.550 TA.T01 03 State change >> TAOutGoing->TAConnectWaitOut (TAS_Delivering)
09:27:58.551 SB.CALL 11 Delivering Called the connect routine
09:27:58.551 SB.CCM isResponseMappable:
09:27:58.551 SB.CCM : Call Struct 0x34c8c10 : Call-ID = 11
09:27:58.551 SB.CCM : Org Acct = T02 Dst Acct = T01
09:27:58.552 SB.CCM : Org Port ID = Isdn(Ds1Ds0Trunk) 0/3.1 Dst Port ID = SipTrunk 0/0.2
09:27:58.552 SB.CCM : SDP Transaction = CallID: 11
09:27:58.552 SB.CCM : SDP Offer = 0x034dd110, (127.0.0.3:10038)
09:27:58.552 SB.CCM : SDP Answer = 0x034f2910, (75.98.50.46:32100)
09:27:58.552 SB.CCM : RTP Channel = 0/1.1
09:27:58.553 SB.CCM isResponseMappable: reversing call connection type to compensate for event originator direction
09:27:58.553 SB.CCM isResponseMappable: Call Connection Type is RTP_TO_TDM
09:27:58.553 SB.CCM isResponseMappable: Modifying SDP Answer
09:27:58.553 SB.CCM translateAnswer: offer codec list: PCMU G729
09:27:58.554 SB.CCM : answer codec list: PCMU
09:27:58.554 SB.CCM translateAnswer: CODEC transcoding is not required
09:27:58.554 SB.CCM translateAnswer: offer / answer DTMF signaling identical: DTMF transcoding not required
09:27:58.555 SB.CCM translateAnswer: success
09:27:58.555 SB.CALL 11 Delivering Connect sent from T01 to T02
09:27:58.556 SB.CALL 11 State change >> Delivering->Connecting
09:27:58.556 TA.T02 23 TAConnectWaitIn connect event accepted
09:27:58.556 TA.T02 23 State change >> TAConnectWaitIn->TAConnectPending (TAS_Connected)
09:27:58.556 TM.T02 23 IsdnTmStateInboundAccept->IsdnTmStateInboundConnecting
09:27:58.556 TM.T02 23 IsdnTmStateInboundConnecting::enter()
09:27:58.557 TM.T02 23 IsdnTmStateInboundConnecting->IsdnTmStateInboundConnected
09:27:58.557 TM.T02 23 IsdnTmStateInboundConnected::enter()
09:27:58.557 ISDN.L2_FMT PRI 1 ==============================================
09:27:58.557 ISDN.L2_FMT PRI 1 T Sapi:00 C/R:C Tei:00 INFO Ns:102 Nr:105 P:0
09:27:58.557 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:8017
09:27:58.558 ISDN.L2_FMT PRI 1 M - 07 CONNECT
09:27:58.558 TA.T02 23 TAConnectPending rcvd: connect from TM
09:27:58.558 TA.T02 23 State change >> TAConnectPending->TAConnected (TAS_Connected)
09:27:58.558 SB.CALL 11 Connecting Called the connectResponse routine
09:27:58.558 SB.CCM connect:
09:27:58.559 SB.CCM : Call Struct 0x34c8c10 : Call-ID = 11
09:27:58.559 SB.CCM : Org Acct = T02 Dst Acct = T01
09:27:58.559 SB.CCM : Org Port ID = Isdn(Ds1Ds0Trunk) 0/3.1 Dst Port ID = SipTrunk 0/0.2
09:27:58.559 SB.CCM : SDP Transaction = CallID: 11
09:27:58.560 SB.CCM : SDP Offer = 0x034dd110, (127.0.0.3:10038)
09:27:58.560 SB.CCM : SDP Answer = 0x034f2910, (75.98.50.46:32100)
09:27:58.560 SB.CCM : RTP Channel = 0/1.1
09:27:58.560 SB.CCM connect: Call Connection Type is TDM_TO_RTP
09:27:58.561 SB.CCM SDP offer is 127.0.0.3:10038, SDP answer is 75.98.50.46:32100
09:27:58.561 SIP.CLDU Looking up source address for destination 75.98.50.46
09:27:58.562 SIP.CLDU Looking up source address for destination 75.98.50.46
09:27:58.562 SB.CCM connect: Connected RTP/TDM via MCM
09:27:58.562 SB.CCM setupRtpChannel, source 2, silence 0
09:27:58.563 SB.CCM setupRtpChannel: setup using media connection
09:27:58.563 SB.CCM Looking up source address for destination 75.98.50.46
09:27:58.563 SB.CCM setupRtpChannel: Source IP addr = 172.16.30.40, port = 10038
09:27:58.563 SB.CCM setupRtpChannel: Target IP addr = 75.98.50.46, port = 32100
09:27:58.564 SB.CCM setupRtpChannel: Undo of previous operation not required
09:27:58.564 SB.CCM getFinalCodec: PCMU
09:27:58.564 SB.CCM getFinalCodec: PCMU
09:27:58.565 SB.CCM setupRtpChannel: Configuring RTP Channel 0/1.1 to Src 172.16.30.40:10038 Trg 75.98.50.46:32100 via PCMU Rx PCMU G729
09:27:58.565 SB.CCM setupRtpChannel: fpp=2 echo=on dtmf=101/101 dscp=46 vad=off isOffer yes
09:27:58.565 SB.CCM setupRtpChannel: Starting RTP Channel
09:27:58.566 RTP.CHANNEL Channel 0/1.1 session statistics cleared.
09:27:58.566 RTP.CHANNEL Channel 0/1.1 started successfully.
09:27:58.566 SB.CCM firewallConnectCall: Set up firewall from media connections
09:27:58.566 SB.CCM sdpFirewall: invoked with offer - 172.16.30.40:10038, answer - 75.98.50.46:32100
09:27:58.566 SB.CCM sdpFirewall: IPv4 firewall is not enabled, no action taken
09:27:58.567 SB.CCM connect: TDM streams: port(Isdn(Ds1Ds0Trunk) 0/3.1) to port(SipTrunk 0/1.1)
09:27:58.567 SB.CALL 11 Connecting ConnectResponse sent from T02 to T01
09:27:58.568 RTP.CHANNEL t1 0/3.1 - Dsp 0/1.1 - RTP: starting
09:27:58 SB.CallStructObserver 11 <-> 52d06c0-7f000001-13c4-30bc-e507c3f7-30bc@wkmc.20139.service
09:27:58.569 TA.T01 03 TAConnectWaitOut connectResponse event accepted
09:27:58.569 TA.T01 03 State change >> TAConnectWaitOut->TAConnected (TAS_Connected)
09:27:58.569 TM.T01 03 SipTM_Answering tachg -> TAConnected
09:27:58.569 SIP.STACK DEBUG CALL RvSipCallLegGetCallId - getting call id for call-leg 0x52d06c0
09:27:58.570 TM.T01 03 SipTM_Answering State change >> SipTM_Answering->SipTM_Acking
09:27:58.570 TM.T01 03 SipTM_Acking sent: finalizeConnect to TA
09:27:58.570 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce1090)=0 (MessagePool)
09:27:58.570 SIP.STACK DEBUG MESSAGE RvSipMsgConstruct - Got a new page. hPage is 0x3ce1090.
09:27:58.571 SIP.STACK DEBUG TRANSACTION TransactionCreateRequestMessage - Transaction 0x5279a58: A request message was successfully created in a transaction
09:27:58.571 SIP.STACK DEBUG TRANSACTION TransactionCallbackMsgToSendEv: Transc 0x5279a58, Before callback
09:27:58.571 SIP.STACK DEBUG CALL CallLegMsgEvMsgToSendHandler - Call-Leg 0x52d06c0 - Is about to send a message
09:27:58.571 SIP.STACK DEBUG CALL AddContactHeaderToMsg - Call Leg 0x52d06c0 ,Contact header was added to msg 0x3ce10b0 successfully
09:27:58.572 SIP.STACK DEBUG CALL CallLegCallbackMsgToSendEv: CallLeg 0x52d06c0, Before callback
09:27:58.572 SIP.STACK DEBUG RPOOL RPOOL_Append - (pool=0x3b9f010,element=0x3ce1090,size=40,consecutiveMemory=1,*AllocationOffset=0x5f8) new block appended (MessagePool)
09:27:58.572 SIP.STACK DEBUG RA RA_Construct for P-Asserted-Identity-Encoding-PoM allocate 2112 bytes. Total 24394404
09:27:58.573 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3501020,size=0,*newRpoolElem=0x35010c8)=0 (P-Asserted-Identity-Encoding-PoM)
09:27:58.573 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3501020,size=0,*newRpoolElem=0x35014e8)=0 (P-Asserted-Identity-Encoding-PoM)
09:27:58.573 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3501120, hPool 0x3501020, hPage 55579880
09:27:58.573 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3501120, hPool 0x3501020, hPage 55579880
09:27:58.574 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3501020,element=0x35014e8) (P-Asserted-Identity-Encoding-PoM)
09:27:58.574 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3501020,element=0x35010c8) (P-Asserted-Identity-Encoding-PoM)
09:27:58.574 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce12d0
09:27:58.574 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce13d8
09:27:58.575 SIP.STACK DEBUG CALL CallLegCallbackMsgToSendEv - call-leg 0x52d06c0 After callback
09:27:58.575 SIP.STACK DEBUG TRANSACTION TransactionCallbackMsgToSendEv: Transc 0x5279a58,After callback (rv=0)
09:27:58.575 SIP.STACK DEBUG TRANSACTION TransactionTransportSendMsg - Transaction 0x5279a58 is about to send message 0x3ce10b0. msgType = Ack Sent, bResolveAddress = 1
09:27:58.575 SIP.STACK DEBUG TRANSMITTER CheckForOutboundAddress - returning IP String 75.98.50.46:5060;transport=UDP
09:27:58.575 SIP.STACK DEBUG TRANSMITTER GetRequestAddressFromMsg - trx=0x526d420: outbound address will be used
09:27:58.576 SIP.STACK DEBUG TRANSMITTER TransmitterDestIdentifyDestAddress - pTrx=0x211c9cf: address was not resolved, Will try to discover address
09:27:58.576 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d420 state changed: Msg Sent->Resolving Addr, (reason = Undefined)
09:27:58.576 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420 - Before callback
09:27:58.576 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420,After callback
09:27:58.577 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d420 state changed: Resolving Addr->Final Dest Resolved, (reason = Undefined)
09:27:58.577 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420 - Before callback
09:27:58.577 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc 0x5279a58 - Destination address is: ip=75.98.50.46, port=5060, transport=UDP, address type=IPv4
09:27:58.577 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc=0x5279a58, hMsg=0x3ce10b0, Before callback
09:27:58.578 SIP.STACK DEBUG CALL CallLegCallbackFinalDestResolvedEv: CallLeg=0x52d06c0, Transc=0x5279a58, appTransc=0x0, hMsg=0x3ce10b0, Application did not register to callback
09:27:58.578 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc 0x5279a58,After callback (rv=0)
09:27:58.578 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420,After callback
09:27:58.578 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d420 state changed: Final Dest Resolved->Ready For Sending, (reason = Undefined)
09:27:58.578 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420 - Before callback
09:27:58.579 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420,After callback
09:27:58.579 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce78b0)=0 (MessagePool)
09:27:58.579 SIP.STACK DEBUG MESSAGE RvSipMsgEncode - Got new page 0x3ce78b0 on pool 0x3b9f010. hSipMsg is 0x3ce10b0
09:27:58.579 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce1108, hPool 0x3b9f010, hPage 63862960
09:27:58.579 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce1108, hPool 0x3b9f010, hPage 63862960
09:27:58.580 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce12d0, hPool 0x3b9f010, hPage 63862960
09:27:58.580 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce12d0, hPool 0x3b9f010, hPage 63862960
09:27:58.580 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce13d8, hPool 0x3b9f010, hPage 63862960
09:27:58.580 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce13d8, hPool 0x3b9f010, hPage 63862960
09:27:58.581 SIP.STACK DEBUG MESSAGE RvSipCSeqHeaderEncode - Encoding CSeq header. hHeader 0x3ce11a8, hPool 0x3b9f010, hPage 63862960
09:27:58.581 SIP.STACK DEBUG MESSAGE RvSipViaHeaderEncode - Via header 0x3ce11d0 was encoded successfully.
09:27:58.581 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce15b0, hPool 0x3b9f010, hPage 63862960
09:27:58.582 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce15b0, hPool 0x3b9f010, hPage 63862960
09:27:58.582 SIP.STACK DEBUG TRANSMITTER TransmitterMsgToSendListAddElement - Transmitter 0x526d420, adding page 0x3ce78b0
09:27:58.582 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce1090) (MessagePool)
09:27:58.582 SIP.STACK DEBUG TRANSPORT SipTransportUdpSendMessage - sock 27: Sending UDP message. 172.16.30.40:5060->75.98.50.46:5060, size=717
09:27:58.583 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgToSendEv: Application did not register to call back, default bSendMsg = 1
09:27:58.583 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferToSend: Application did not register to call back, default *bDiscardBuffer=FALSE
09:27:58.583 SIP.STACK DEBUG TRANSMITTER TransmitterControlTransmitMessage - pTrx=0x526d420: A message was successfully sent over UDP.
09:27:58.583 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce6030) (MessagePool)
09:27:58.584 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d420 state changed: Ready For Sending->Msg Sent, (reason = Undefined)
09:27:58.584 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420 - Before callback
09:27:58.584 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x5279a58: Setting timers
09:27:58.584 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=5279b48; event=3f5f0c8)
09:27:58.585 SIP.STACK DEBUG TRANSACTION TransactionTimerSetTimers - Transaction 0x5279a58: timer was set to 32000 milliseconds
09:27:58.585 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d420,After callback
09:27:58.585 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279a58, Before callback
09:27:58.586 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279a58,After callback
09:27:58.586 SIP.STACK DEBUG CALL CallLegCallbackChangeCallStateEv - call-leg 0x52d06c0, Before callback
09:27:58.586 SIP.CLDU Cldu::CallLegStateChangedEv: (0x52d06c0)->Connected
09:27:58.586 TM.T01 03 SipTM_Acking call-leg -> Connected
09:27:58.586 TM.T01 03 SipTM_Acking State change >> SipTM_Acking->SipTM_Connected
09:27:58.587 SIP.STACK DEBUG CALL CallLegCallbackChangeCallStateEv - call-leg 0x52d06c0 After callback
09:27:58.587 SIP.STACK DEBUG CALL CallLegCallbackChangeModifyStateEv:CallLeg 0x52d06c0, Before callback
09:27:58.587 SIP.CLDU Cldu::CallLegModifyStateChangedEv: (0x52d06c0)->Modify Idle
09:27:58.587 TM.T01 03 SipTM_Connected call-leg-mod -> Modify Idle
09:27:58.588 SIP.STACK DEBUG CALL CallLegCallbackChangeModifyStateEv - call-leg 0x52d06c0 After callback
09:27:58.588 TM.T01 03 SipTM_Acking sent: ACK
09:27:58.588 SIP.STACK DEBUG SELECT Occured event: fd=21,event=Read ,error=0
09:27:58.588 SIP.STACK DEBUG SELECT rvFdPreemptionCallback, received 0 preemption message
09:27:58.589 TA.T01 03 TAConnected rcvd: finalizeConnect from TM
09:27:58.589 TA.T01 03 TAConnected forwarding finalizeConnect from TM
09:27:58.589 TA.T01 03 TAConnected sent finalizeConnect to SB
09:27:58.589 SB.CALL 11 Connecting Called the finalizeConnect routine
09:27:58.590 SB.CCM finalizeConnect: connection already finalized(2)
09:27:58.590 SB.CALL 11 State change >> Connecting->Connected
09:27:58.677 ISDN.L2_FMT PRI 1 ==============================================
09:27:58.677 ISDN.L2_FMT PRI 1 R Sapi:00 C/R:R Tei:00 INFO Ns:105 Nr:103 P:0
09:27:58.677 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:0017
09:27:58.677 ISDN.L2_FMT PRI 1 M - 0F CONNECT_ACK
09:28:03.100 SIP.STACK DEBUG TIMER RvTimerQueueService: timer expired(tqueue=3ddd6b4; event=3f5f078)
09:28:03.100 SIP.STACK DEBUG TRANSPORT TransportMultiThreadTimerEventHandler - Allocating timer expired event
09:28:03.101 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - TIMER_EXPIRED_EVENT 0x4017db8
09:28:03.101 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - TIMER_EXPIRED_EVENT 0x4017db8
09:28:03.101 SIP.STACK DEBUG TIMER RvTimerQueueService: timer expired(tqueue=3ddd6b4; event=3f5f078)
09:28:03.101 SIP.STACK DEBUG TRANSACTION TransactionTimerHandleMainTimerTimeout - Transaction 0x5279648: timer expired (transc state=Client General Final Response Rcvd)
09:28:03.102 SIP.STACK DEBUG TRANSACTION TransactionTerminate - Transaction 0x5279648: Termination called
09:28:03.102 SIP.STACK DEBUG TRANSACTION TransactionTransportDetachAllConnections - Transaction 0x5279648: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)
09:28:03.102 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - pObj=0x5279648,pEventInfo=0x5279648,eNum=10,bInternal=1
09:28:03.102 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - INTERNAL_EVENT ev=0x4017e00: Transaction 0x5279648: Terminated
09:28:03.102 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - ev 0x4017e00 sent. (Transaction 0x5279648: Terminated)
09:28:03.103 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - INTERNAL_EVENT ev:0x4017e00, (Transaction 0x5279648: Terminated)
09:28:03.103 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279648, Before callback
09:28:03.103 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279648,After callback
09:28:03.103 SIP.STACK DEBUG TRANSACTION TransactionDestruct - Transaction 0x5279648: start to destruct transaction
09:28:03.104 SIP.STACK DEBUG TRANSACTION TransactionTransportDetachAllConnections - Transaction 0x5279648: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)
09:28:03.104 SIP.STACK DEBUG TRANSMITTER TransmitterDestruct - transmitter 0x526ce70 destructing...
09:28:03.104 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce2910) (MessagePool)
09:28:03.104 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e04c10) (GeneralPool)
09:28:03.167 SIP.STACK DEBUG REG_CLIENT RvSipRegClientMgrCreateRegClient - Starting to create reg client
09:28:03.167 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3dde010,size=0,*newRpoolElem=0x3df9690)=0 (GeneralPool)
09:28:03.169 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetLocalAddress - RegClient 0x53113f0 - Setting UDP IPv4 local address 172.16.30.40:5060
09:28:03.169 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetOutboundDetails - Reg-Client 0x53113f0 - Setting an outbound address 75.98.50.46:5060
09:28:03.170 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetOutboundDetails - Reg-Client 0x53113f0 - Setting outbound transport to UDP
09:28:03.170 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetFromHeader - Setting Register-Client 0x53113f0 From header
09:28:03.170 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetToHeader - Setting Register-Client 0x53113f0 To header
09:28:03.170 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3df9888
09:28:03.171 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetRegistrar - Setting Register-Client 0x53113f0 registrar Request-Url
09:28:03.171 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3df9888
09:28:03.171 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetRegistrar - Setting Register-Client 0x53113f0 registrar Request-Url
09:28:03.171 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetContactHeader - Setting Register-Client 0x53113f0 Contact header
09:28:03.172 SIP.STACK DEBUG RPOOL RPOOL_Append - (pool=0x3dde010,element=0x3df9690,size=24,consecutiveMemory=1,*AllocationOffset=0x400) new block appended (GeneralPool)
09:28:03.172 SIP.STACK DEBUG REG_CLIENT RvSipRegClientSetExpiresHeader - Setting Register-Client 0x53113f0 Expires header
09:28:03.172 SIP.STACK DEBUG REG_CLIENT RvSipRegClientRegister - Register client 0x53113f0
09:28:03.173 SIP.STACK DEBUG TRANSACTION TransactionMgrCreateTransaction - About to create a new transaction
09:28:03.173 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3dde010,size=0,*newRpoolElem=0x3e068f0)=0 (GeneralPool)
09:28:03.173 SIP.STACK DEBUG TRANSMITTER TransmitterMgrCreateTransmitter - Creating a new transmitter...
09:28:03.173 SIP.STACK DEBUG TRANSMITTER TransmitterMgrCreateTransmitter - Transmitter 0x526d148 was created successfully, pTripleLock=0x526d188
09:28:03.173 SIP.STACK DEBUG TRANSACTION TransactionAttachKey - Transaction 0x5279c60 - Key was attached successfully
09:28:03.174 SIP.STACK DEBUG REG_CLIENT RegClientCreateNewTransaction - Register client 0x53113f0 created new transc 0x5279c60
09:28:03.174 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce5a10)=0 (MessagePool)
09:28:03.174 SIP.STACK DEBUG MESSAGE RvSipMsgConstruct - Got a new page. hPage is 0x3ce5a10.
09:28:03.175 SIP.STACK DEBUG TRANSACTION TransactionCreateRequestMessage - Transaction 0x5279c60: A request message was successfully created in a transaction
09:28:03.175 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x5279c60: Copied the top via header from message into the transc object.
09:28:03.175 SIP.STACK DEBUG TRANSACTION TransactionCallbackMsgToSendEv: Transc 0x5279c60, Before callback
09:28:03.175 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgToSendEv: Register-client 0x53113f0, Before callback
09:28:03.176 SIP.STACK DEBUG RPOOL RPOOL_Append - (pool=0x3b9f010,element=0x3ce5a10,size=40,consecutiveMemory=1,*AllocationOffset=0x600) new block appended (MessagePool)
09:28:03.176 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce5c50
09:28:03.176 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce5d58
09:28:03.177 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgToSendEv: Register-client 0x53113f0,After callback
09:28:03.177 SIP.STACK DEBUG TRANSACTION TransactionCallbackMsgToSendEv: Transc 0x5279c60,After callback (rv=0)
09:28:03.177 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x5279c60: Copied the top via header from message into the transc object.
09:28:03.177 SIP.STACK DEBUG TRANSACTION TransactionMgrHashInsert - Transc=0x5279c60 was inserted to hash
09:28:03.177 SIP.STACK DEBUG TRANSACTION TransactionTransportSendMsg - Transaction 0x5279c60 is about to send message 0x3ce5a30. msgType = Request Sent, bResolveAddress = 1
09:28:03.178 SIP.STACK DEBUG TRANSMITTER CheckForOutboundAddress - returning IP String 75.98.50.46:5060;transport=UDP
09:28:03.178 SIP.STACK DEBUG TRANSMITTER GetRequestAddressFromMsg - trx=0x526d148: outbound address will be used
09:28:03.178 SIP.STACK DEBUG TRANSMITTER TransmitterDestIdentifyDestAddress - pTrx=0x211c9cf: address was not resolved, Will try to discover address
09:28:03.178 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d148 state changed: Idle->Resolving Addr, (reason = Undefined)
09:28:03.178 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d148 - Before callback
09:28:03.179 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d148,After callback
09:28:03.179 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d148 state changed: Resolving Addr->Final Dest Resolved, (reason = Undefined)
09:28:03.179 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d148 - Before callback
09:28:03.179 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc 0x5279c60 - Destination address is: ip=75.98.50.46, port=5060, transport=UDP, address type=IPv4
09:28:03.180 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc=0x5279c60, hMsg=0x3ce5a30, Before callback
09:28:03.180 SIP.STACK DEBUG REG_CLIENT RegClientCallbackFinalDestResolvedEv: hRegClient=0x53113f0, hAppRegClient=0x3564010, hTransc=0x5279c60, hMsg=0x3ce5a30,Application did not registered to callback
09:28:03.180 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc 0x5279c60,After callback (rv=0)
09:28:03.180 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d148,After callback
09:28:03.180 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d148 state changed: Final Dest Resolved->Ready For Sending, (reason = Undefined)
09:28:03.181 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d148 - Before callback
09:28:03.181 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x5279c60: Copied the top via header from message into the transc object.
09:28:03.181 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d148,After callback
09:28:03.181 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce9750)=0 (MessagePool)
09:28:03.182 SIP.STACK DEBUG MESSAGE RvSipMsgEncode - Got new page 0x3ce9750 on pool 0x3b9f010. hSipMsg is 0x3ce5a30
09:28:03.182 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce5a88, hPool 0x3b9f010, hPage 63870800
09:28:03.182 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce5a88, hPool 0x3b9f010, hPage 63870800
09:28:03.182 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce5c50, hPool 0x3b9f010, hPage 63870800
09:28:03.183 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce5c50, hPool 0x3b9f010, hPage 63870800
09:28:03.183 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce5d58, hPool 0x3b9f010, hPage 63870800
09:28:03.183 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce5d58, hPool 0x3b9f010, hPage 63870800
09:28:03.183 SIP.STACK DEBUG MESSAGE RvSipCSeqHeaderEncode - Encoding CSeq header. hHeader 0x3ce5b28, hPool 0x3b9f010, hPage 63870800
09:28:03.184 SIP.STACK DEBUG MESSAGE RvSipViaHeaderEncode - Via header 0x3ce5b50 was encoded successfully.
09:28:03.184 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce5ef0, hPool 0x3b9f010, hPage 63870800
09:28:03.184 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce5ef0, hPool 0x3b9f010, hPage 63870800
09:28:03.184 SIP.STACK DEBUG TRANSMITTER TransmitterMsgToSendListAddElement - Transmitter 0x526d148, adding page 0x3ce9750
09:28:03.185 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce5a10) (MessagePool)
09:28:03.185 SIP.STACK DEBUG TRANSPORT SipTransportUdpSendMessage - sock 27: Sending UDP message. 172.16.30.40:5060->75.98.50.46:5060, size=615
09:28:03.186 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgToSendEv: Application did not register to call back, default bSendMsg = 1
09:28:03.186 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferToSend: Application did not register to call back, default *bDiscardBuffer=FALSE
09:28:03.186 SIP.STACK DEBUG TRANSMITTER TransmitterControlTransmitMessage - pTrx=0x526d148: A message was successfully sent over UDP.
09:28:03.186 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d148 state changed: Ready For Sending->Msg Sent, (reason = Undefined)
09:28:03.186 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d148 - Before callback
09:28:03.187 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x5279c60: Setting timers
09:28:03.187 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x5279c60: state=Client General Request Sent, Decisions: (*bSetMainTimer=1, *mainTimerInterval=500, *bSetLongReqestTimer=1, *longTimerInterval=32000
09:28:03.187 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=5279d50; event=3f5f078)
09:28:03.188 SIP.STACK DEBUG SELECT Occured event: fd=21,event=Read ,error=0
09:28:03.188 SIP.STACK DEBUG SELECT rvFdPreemptionCallback, received 0 preemption message
09:28:03.189 SIP.STACK DEBUG TRANSACTION TransactionTimerSetTimers - Transaction 0x5279c60: timer was set to 500 milliseconds
09:28:03.189 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=5279d70; event=3f5f118)
09:28:03.190 SIP.STACK DEBUG SELECT Occured event: fd=21,event=Read ,error=0
09:28:03.190 SIP.STACK DEBUG SELECT rvFdPreemptionCallback, received 0 preemption message
09:28:03.190 SIP.STACK DEBUG TRANSACTION TransactionTimerSetTimers - Transaction 0x5279c60: long timeout timer was set to 32000 milliseconds
09:28:03.190 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d148,After callback
09:28:03.191 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279c60, Before callback
09:28:03.191 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279c60,After callback
09:28:03.191 SIP.STACK DEBUG TRANSACTION SipTransactionRequest - Transaction 0x5279c60: Request was sent successfully
09:28:03.191 SIP.STACK DEBUG REG_CLIENT RegClientChangeState - Register-client 0x53113f0 state changed: Idle->Registering, (reason = User request)
09:28:03.191 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0, Before callback
09:28:03.192 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0,After callback
09:28:03.246 SIP.STACK DEBUG SELECT Occured event: fd=27,event=Read ,error=0
09:28:03.246 SIP.STACK DEBUG TRANSPORT TransportMgrAllocateRcvBuffer - Successfully allocated buffer 0x49560e8
09:28:03.246 SIP.STACK DEBUG TRANSPORT TransportUdpEventCallback - sock 27: Recv new UDP message. 172.16.30.40:5060<-75.98.50.46:5060, size=477
09:28:03.246 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - MESSAGE_RCVD_EVENT 0x4017e48, buffer 0x49560e8
09:28:03.247 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - MESSAGE_RCVD_EVENT 0x4017e48, buffer 0x49560e8
09:28:03.247 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=477 Before callback
09:28:03.247 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: bDiscardBuffer=FALSE, Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=477 After callback
09:28:03.247 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce53f0)=0 (MessagePool)
09:28:03.248 SIP.STACK DEBUG MESSAGE RvSipMsgConstruct - Got a new page. hPage is 0x3ce53f0.
09:28:03.248 SIP.STACK DEBUG MESSAGE RvSipViaHeaderSetCompactForm - Setting compact form of Header 0x3ce5568 to 0
09:28:03.249 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3ce5620 to 0
09:28:03.249 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3ce5700 to 0
09:28:03.250 SIP.STACK DEBUG MESSAGE RvSipMsgSetContentLengthCompactForm - Setting compact form of Content-Length for hMsg 0x3ce5410 to 0
09:28:03.250 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3ce5410: Before callback
09:28:03.250 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce5738
09:28:03.250 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce5658
09:28:03.251 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3ce5410: After callback, bProcessMsg = 1
09:28:03.251 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3ce5410 Before callback (bsAction=Continue)
09:28:03.251 SIP.STACK DEBUG TRANSACTION HandleIncomingResponseMsg - A response msg 0x3ce5410- starting to process...
09:28:03.251 SIP.STACK DEBUG TRANSACTION HashKeyMethodsAreEqual - Methods are equal (REGISTER)
09:28:03.252 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x5279c60, Before callback
09:28:03.252 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgReceivedEv: Register-client 0x53113f0, Before callback
09:28:03.252 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgReceivedEv: Register-client 0x53113f0,After callback
09:28:03.252 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3dde010,size=0,*newRpoolElem=0x3e03350)=0 (GeneralPool)
09:28:03.253 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x5279c60,After callback (rv=0)
09:28:03.253 SIP.STACK DEBUG TRANSACTION TransactionTimerReleaseAllTimers - Transaction 0x5279c60: Timeout timer was released
09:28:03.253 SIP.STACK DEBUG TRANSACTION TransactionTimerMainTimerRelease - Transaction 0x5279c60: Timer 0x5279d50 was released
09:28:03.253 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279c60, Before callback
09:28:03.253 SIP.STACK DEBUG TRANSACTION RvSipTransactionGetReceivedMsg - transc= 0x5279c60 returned handle= 0x3ce5410
09:28:03.254 SIP.STACK DEBUG REG_CLIENT RegClientChangeState - Register-client 0x53113f0 state changed: Registering->Unauthenticated, (reason = Response unauthentication received)
09:28:03.254 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0, Before callback
09:28:03.254 SIP.STACK DEBUG REG_CLIENT RvSipRegClientAuthenticate - Register client 0x53113f0
09:28:03.254 SIP.STACK DEBUG TRANSACTION SipTransactionDetachOwner - transc 0x5279c60, calling TransactionNoOwner()
09:28:03.255 SIP.STACK DEBUG TRANSACTION SipTransactionDetachOwner - Transaction 0x5279c60: Detached successfully
09:28:03.255 SIP.STACK DEBUG TRANSACTION TransactionMgrCreateTransaction - About to create a new transaction
09:28:03.255 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3dde010,size=0,*newRpoolElem=0x3e07550)=0 (GeneralPool)
09:28:03.255 SIP.STACK DEBUG TRANSMITTER TransmitterMgrCreateTransmitter - Creating a new transmitter...
09:28:03.256 SIP.STACK DEBUG TRANSMITTER TransmitterMgrCreateTransmitter - Transmitter 0x526d9d0 was created successfully, pTripleLock=0x526da10
09:28:03.256 SIP.STACK DEBUG TRANSACTION TransactionAttachKey - Transaction 0x5279e68 - Key was attached successfully
09:28:03.256 SIP.STACK DEBUG REG_CLIENT RegClientCreateNewTransaction - Register client 0x53113f0 created new transc 0x5279e68
09:28:03.256 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce84f0)=0 (MessagePool)
09:28:03.256 SIP.STACK DEBUG MESSAGE RvSipMsgConstruct - Got a new page. hPage is 0x3ce84f0.
09:28:03.257 SIP.STACK DEBUG TRANSACTION TransactionCreateRequestMessage - Transaction 0x5279e68: A request message was successfully created in a transaction
09:28:03.257 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x5279e68: Copied the top via header from message into the transc object.
09:28:03.257 SIP.STACK DEBUG TRANSACTION TransactionCallbackMsgToSendEv: Transc 0x5279e68, Before callback
09:28:03.258 SIP.STACK DEBUG RPOOL RPOOL_Append - (pool=0x3b9f010,element=0x3ce84f0,size=128,consecutiveMemory=1,*AllocationOffset=0x5a8) new block appended (MessagePool)
09:28:03.258 SIP.STACK DEBUG AUTH AuthenticatorCallbackGetSharedSecret - before callback
09:28:03.258 SIP.STACK DEBUG AUTH AuthenticatorCallbackGetSharedSecret - after callback
09:28:03.259 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3dde010,size=0,*newRpoolElem=0x3e081b0)=0 (GeneralPool)
09:28:03.259 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce8568, hPool 0x3dde010, hPage 65044912
09:28:03.259 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce8568, hPool 0x3dde010, hPage 65044912
09:28:03.259 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3dde010,size=0,*newRpoolElem=0x3e08e10)=0 (GeneralPool)
09:28:03.260 SIP.STACK DEBUG AUTH AuthenticatorCallbackMD5Calculate - Before callback
09:28:03.260 SIP.STACK DEBUG AUTH AuthenticatorCallbackMD5Calculate - After callback
09:28:03.260 SIP.STACK DEBUG AUTH AuthenticatorCallbackMD5Calculate - Before callback
09:28:03.260 SIP.STACK DEBUG AUTH AuthenticatorCallbackMD5Calculate - After callback
09:28:03.261 SIP.STACK DEBUG AUTH AuthenticatorCallbackMD5Calculate - Before callback
09:28:03.261 SIP.STACK DEBUG AUTH AuthenticatorCallbackMD5Calculate - After callback
09:28:03.261 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e081b0) (GeneralPool)
09:28:03.261 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3dde010,size=0,*newRpoolElem=0x3e09230)=0 (GeneralPool)
09:28:03.262 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e09230) (GeneralPool)
09:28:03.262 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e08e10) (GeneralPool)
09:28:03.262 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgToSendEv: Register-client 0x53113f0, Before callback
09:28:03.262 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce8730
09:28:03.263 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce8838
09:28:03.263 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgToSendEv: Register-client 0x53113f0,After callback
09:28:03.263 SIP.STACK DEBUG TRANSACTION TransactionCallbackMsgToSendEv: Transc 0x5279e68,After callback (rv=0)
09:28:03.263 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x5279e68: Copied the top via header from message into the transc object.
09:28:03.264 SIP.STACK DEBUG TRANSACTION TransactionMgrHashInsert - Transc=0x5279e68 was inserted to hash
09:28:03.264 SIP.STACK DEBUG TRANSACTION TransactionTransportSendMsg - Transaction 0x5279e68 is about to send message 0x3ce8510. msgType = Request Sent, bResolveAddress = 1
09:28:03.264 SIP.STACK DEBUG TRANSMITTER CheckForOutboundAddress - returning IP String 75.98.50.46:5060;transport=UDP
09:28:03.264 SIP.STACK DEBUG TRANSMITTER GetRequestAddressFromMsg - trx=0x526d9d0: outbound address will be used
09:28:03.264 SIP.STACK DEBUG TRANSMITTER TransmitterDestIdentifyDestAddress - pTrx=0x211c9cf: address was not resolved, Will try to discover address
09:28:03.265 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d9d0 state changed: Idle->Resolving Addr, (reason = Undefined)
09:28:03.265 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d9d0 - Before callback
09:28:03.265 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d9d0,After callback
09:28:03.265 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d9d0 state changed: Resolving Addr->Final Dest Resolved, (reason = Undefined)
09:28:03.266 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d9d0 - Before callback
09:28:03.266 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc 0x5279e68 - Destination address is: ip=75.98.50.46, port=5060, transport=UDP, address type=IPv4
09:28:03.266 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc=0x5279e68, hMsg=0x3ce8510, Before callback
09:28:03.266 SIP.STACK DEBUG REG_CLIENT RegClientCallbackFinalDestResolvedEv: hRegClient=0x53113f0, hAppRegClient=0x3564010, hTransc=0x5279e68, hMsg=0x3ce8510,Application did not registered to callback
09:28:03.267 SIP.STACK DEBUG TRANSACTION TransactionCallbackFinalDestResolvedEv - Transc 0x5279e68,After callback (rv=0)
09:28:03.267 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d9d0,After callback
09:28:03.267 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d9d0 state changed: Final Dest Resolved->Ready For Sending, (reason = Undefined)
09:28:03.267 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d9d0 - Before callback
09:28:03.268 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x5279e68: Copied the top via header from message into the transc object.
09:28:03.268 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d9d0,After callback
09:28:03.268 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce47b0)=0 (MessagePool)
09:28:03.268 SIP.STACK DEBUG MESSAGE RvSipMsgEncode - Got new page 0x3ce47b0 on pool 0x3b9f010. hSipMsg is 0x3ce8510
09:28:03.268 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce8568, hPool 0x3b9f010, hPage 63850416
09:28:03.269 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce8568, hPool 0x3b9f010, hPage 63850416
09:28:03.269 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce8730, hPool 0x3b9f010, hPage 63850416
09:28:03.269 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce8730, hPool 0x3b9f010, hPage 63850416
09:28:03.270 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce8838, hPool 0x3b9f010, hPage 63850416
09:28:03.270 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce8838, hPool 0x3b9f010, hPage 63850416
09:28:03.270 SIP.STACK DEBUG MESSAGE RvSipCSeqHeaderEncode - Encoding CSeq header. hHeader 0x3ce8608, hPool 0x3b9f010, hPage 63850416
09:28:03.270 SIP.STACK DEBUG MESSAGE RvSipViaHeaderEncode - Via header 0x3ce8630 was encoded successfully.
09:28:03.271 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce89d0, hPool 0x3b9f010, hPage 63850416
09:28:03.271 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce89d0, hPool 0x3b9f010, hPage 63850416
09:28:03.272 SIP.STACK DEBUG MESSAGE AuthorizationHeaderEncode - Encoding Authorization header. hHeader 0x3ce9d88, hPool 0x3b9f010, hPage 63850416
09:28:03.272 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ce9e50, hPool 0x3b9f010, hPage 63850416
09:28:03.272 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ce9e50, hPool 0x3b9f010, hPage 63850416
09:28:03.272 SIP.STACK DEBUG TRANSMITTER TransmitterMsgToSendListAddElement - Transmitter 0x526d9d0, adding page 0x3ce47b0
09:28:03.272 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce84f0) (MessagePool)
09:28:03.273 SIP.STACK DEBUG TRANSPORT SipTransportUdpSendMessage - sock 27: Sending UDP message. 172.16.30.40:5060->75.98.50.46:5060, size=820
09:28:03.273 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgToSendEv: Application did not register to call back, default bSendMsg = 1
09:28:03.273 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferToSend: Application did not register to call back, default *bDiscardBuffer=FALSE
09:28:03.273 SIP.STACK DEBUG TRANSMITTER TransmitterControlTransmitMessage - pTrx=0x526d9d0: A message was successfully sent over UDP.
09:28:03.274 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526d9d0 state changed: Ready For Sending->Msg Sent, (reason = Undefined)
09:28:03.274 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d9d0 - Before callback
09:28:03.274 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x5279e68: Setting timers
09:28:03.274 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x5279e68: state=Client General Request Sent, Decisions: (*bSetMainTimer=1, *mainTimerInterval=500, *bSetLongReqestTimer=1, *longTimerInterval=32000
09:28:03.275 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=5279f58; event=3f5f078)
09:28:03.275 SIP.STACK DEBUG TRANSACTION TransactionTimerSetTimers - Transaction 0x5279e68: timer was set to 500 milliseconds
09:28:03.275 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=5279f78; event=3f5f118)
09:28:03.275 SIP.STACK DEBUG TRANSACTION TransactionTimerSetTimers - Transaction 0x5279e68: long timeout timer was set to 32000 milliseconds
09:28:03.275 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526d9d0,After callback
09:28:03.276 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279e68, Before callback
09:28:03.276 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279e68,After callback
09:28:03.276 SIP.STACK DEBUG TRANSACTION SipTransactionRequest - Transaction 0x5279e68: Request was sent successfully
09:28:03.276 SIP.STACK DEBUG REG_CLIENT RegClientChangeState - Register-client 0x53113f0 state changed: Unauthenticated->Registering, (reason = User request)
09:28:03.276 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0, Before callback
09:28:03.277 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0,After callback
09:28:03.277 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0,After callback
09:28:03.277 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279c60,After callback
09:28:03.277 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=5279d50; event=3f5f028)
09:28:03.278 SIP.STACK DEBUG TRANSACTION TransactionStateUacGeneralFinalResponseRcvd - Transaction 0x5279c60: timer 0x5279d50 was set to 5000 milliseconds
09:28:03.278 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3ce5410 After callback
09:28:03.278 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce53f0) (MessagePool)
09:28:03.336 SIP.STACK DEBUG SELECT Occured event: fd=27,event=Read ,error=0
09:28:03.337 SIP.STACK DEBUG TRANSPORT TransportMgrAllocateRcvBuffer - Successfully allocated buffer 0x495e0e8
09:28:03.337 SIP.STACK DEBUG TRANSPORT TransportUdpEventCallback - sock 27: Recv new UDP message. 172.16.30.40:5060<-75.98.50.46:5060, size=518
09:28:03.337 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - MESSAGE_RCVD_EVENT 0x4017e90, buffer 0x495e0e8
09:28:03.337 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - MESSAGE_RCVD_EVENT 0x4017e90, buffer 0x495e0e8
09:28:03.338 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=518 Before callback
09:28:03.338 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: bDiscardBuffer=FALSE, Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=518 After callback
09:28:03.338 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3ce6c70)=0 (MessagePool)
09:28:03.339 SIP.STACK DEBUG MESSAGE RvSipMsgConstruct - Got a new page. hPage is 0x3ce6c70.
09:28:03.339 SIP.STACK DEBUG MESSAGE RvSipViaHeaderSetCompactForm - Setting compact form of Header 0x3ce6cf0 to 0
09:28:03.340 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3ce6dc0 to 0
09:28:03.340 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3ce6ea0 to 0
09:28:03.341 SIP.STACK DEBUG MESSAGE RvSipContactHeaderSetCompactForm - Setting compact form of hHeader 0x3ce7028 to 0
09:28:03.341 SIP.STACK DEBUG RPOOL RPOOL_Append - (pool=0x3b9f010,element=0x3ce6c70,size=16,consecutiveMemory=1,*AllocationOffset=0x600) new block appended (MessagePool)
09:28:03.341 SIP.STACK DEBUG MESSAGE RvSipMsgSetContentLengthCompactForm - Setting compact form of Content-Length for hMsg 0x3ce6c90 to 0
09:28:03.342 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3ce6c90: Before callback
09:28:03.342 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce6ed8
09:28:03.342 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3ce6df8
09:28:03.342 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3ce6c90: After callback, bProcessMsg = 1
09:28:03.343 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3ce6c90 Before callback (bsAction=Continue)
09:28:03.343 SIP.STACK DEBUG TRANSACTION HandleIncomingResponseMsg - A response msg 0x3ce6c90- starting to process...
09:28:03.343 SIP.STACK DEBUG TRANSACTION HashKeyMethodsAreEqual - Methods are equal (REGISTER)
09:28:03.343 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x5279e68, Before callback
09:28:03.344 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgReceivedEv: Register-client 0x53113f0, Before callback
09:28:03.344 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgReceivedEv: Register-client 0x53113f0,After callback
09:28:03.344 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x5279e68,After callback (rv=0)
09:28:03.345 SIP.STACK DEBUG TRANSACTION TransactionTimerReleaseAllTimers - Transaction 0x5279e68: Timeout timer was released
09:28:03.345 SIP.STACK DEBUG TRANSACTION TransactionTimerMainTimerRelease - Transaction 0x5279e68: Timer 0x5279f58 was released
09:28:03.345 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279e68, Before callback
09:28:03.345 SIP.STACK DEBUG TRANSACTION RvSipTransactionGetReceivedMsg - transc= 0x5279e68 returned handle= 0x3ce6c90
09:28:03.345 SIP.STACK DEBUG REG_CLIENT RegClientChangeState - Register-client 0x53113f0 state changed: Registering->Registered, (reason = Response succeessful received)
09:28:03.345 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0, Before callback
09:28:03.346 SIP.STACK DEBUG TRANSACTION SipTransactionDetachOwner - transc 0x5279e68, calling TransactionNoOwner()
09:28:03.346 SIP.STACK DEBUG TRANSACTION SipTransactionDetachOwner - Transaction 0x5279e68: Detached successfully
09:28:03.346 SIP.STACK DEBUG TRANSACTION TransactionTerminate - Transaction 0x5279e68: Termination called
09:28:03.347 SIP.STACK DEBUG TRANSACTION TransactionTransportDetachAllConnections - Transaction 0x5279e68: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)
09:28:03.347 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - pObj=0x5279e68,pEventInfo=0x5279e68,eNum=0,bInternal=1
09:28:03.347 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - INTERNAL_EVENT ev=0x4017ed8: Transaction 0x5279e68: Terminated
09:28:03.347 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - ev 0x4017ed8 sent. (Transaction 0x5279e68: Terminated)
09:28:03.348 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - pObj=0x53113f0,pEventInfo=0x53113f0,eNum=0,bInternal=1
09:28:03.348 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - INTERNAL_EVENT ev=0x4017f20: Reg-Client 0x53113f0: Terminated
09:28:03.348 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - ev 0x4017f20 sent. (Reg-Client 0x53113f0: Terminated)
09:28:03.349 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0,After callback
09:28:03.349 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279e68,After callback
09:28:03.349 SIP.STACK DEBUG TRANSACTION TransactionStateUacGeneralFinalResponseRcvd - Transaction 0x5279e68: was terminated from callback - timers are not set
09:28:03.350 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3ce6c90 After callback
09:28:03.350 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce6c70) (MessagePool)
09:28:03.350 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - INTERNAL_EVENT ev:0x4017ed8, (Transaction 0x5279e68: Terminated)
09:28:03.350 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279e68, Before callback
09:28:03.350 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x5279e68,After callback
09:28:03.350 SIP.STACK DEBUG TRANSACTION TransactionDestruct - Transaction 0x5279e68: start to destruct transaction
09:28:03.351 SIP.STACK DEBUG TRANSACTION TransactionTransportDetachAllConnections - Transaction 0x5279e68: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)
09:28:03.351 SIP.STACK DEBUG TRANSMITTER TransmitterDestruct - transmitter 0x526d9d0 destructing...
09:28:03.351 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce47b0) (MessagePool)
09:28:03.351 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e07550) (GeneralPool)
09:28:03.351 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - INTERNAL_EVENT ev:0x4017f20, (Reg-Client 0x53113f0: Terminated)
09:28:03.352 SIP.STACK DEBUG REG_CLIENT RegClientChangeState - Register-client 0x53113f0 state changed to Terminated, (reason = User request)
09:28:03.352 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0, Before callback
09:28:03.352 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x53113f0,After callback
09:28:03.352 SIP.STACK DEBUG AUTH SipAuthenticatorAuthenticationHeaderFree - Free Authentication header
09:28:03.352 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e03350) (GeneralPool)
09:28:03.353 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3df9690) (GeneralPool)
09:28:08.448 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526dca8 - Before callback
09:28:08.448 SIP.STACK DEBUG TRANSACTION TransactionUpdateTopViaFromMsg - Transaction 0x527a480: Copied the top via header from message into the transc object.
09:28:08.449 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526dca8,After callback
09:28:08.449 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3cee0d0)=0 (MessagePool)
09:28:08.449 SIP.STACK DEBUG MESSAGE RvSipMsgEncode - Got new page 0x3cee0d0 on pool 0x3b9f010. hSipMsg is 0x3cee710
09:28:08.449 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3cee768, hPool 0x3b9f010, hPage 63889616
09:28:08.449 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3cee768, hPool 0x3b9f010, hPage 63889616
09:28:08.450 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3cee930, hPool 0x3b9f010, hPage 63889616
09:28:08.450 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3cee930, hPool 0x3b9f010, hPage 63889616
09:28:08.450 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ceea38, hPool 0x3b9f010, hPage 63889616
09:28:08.450 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ceea38, hPool 0x3b9f010, hPage 63889616
09:28:08.451 SIP.STACK DEBUG MESSAGE RvSipCSeqHeaderEncode - Encoding CSeq header. hHeader 0x3cee808, hPool 0x3b9f010, hPage 63889616
09:28:08.451 SIP.STACK DEBUG MESSAGE RvSipViaHeaderEncode - Via header 0x3cee830 was encoded successfully.
09:28:08.451 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3ceebd0, hPool 0x3b9f010, hPage 63889616
09:28:08.451 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3ceebd0, hPool 0x3b9f010, hPage 63889616
09:28:08.452 SIP.STACK DEBUG MESSAGE AuthorizationHeaderEncode - Encoding Authorization header. hHeader 0x3cec868, hPool 0x3b9f010, hPage 63889616
09:28:08.452 SIP.STACK DEBUG MESSAGE RvSipAddrEncode - Encoding Address. hSipAddr 0x3cec930, hPool 0x3b9f010, hPage 63889616
09:28:08.452 SIP.STACK DEBUG MESSAGE AddrUrlEncode - Encoding Url Address. hSipUrl 0x3cec930, hPool 0x3b9f010, hPage 63889616
09:28:08.452 SIP.STACK DEBUG TRANSMITTER TransmitterMsgToSendListAddElement - Transmitter 0x526dca8, adding page 0x3cee0d0
09:28:08.453 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3cee6f0) (MessagePool)
09:28:08.453 SIP.STACK DEBUG TRANSPORT SipTransportUdpSendMessage - sock 27: Sending UDP message. 172.16.30.40:5060->75.98.50.46:5060, size=820
09:28:08.453 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgToSendEv: Application did not register to call back, default bSendMsg = 1
09:28:08.453 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferToSend: Application did not register to call back, default *bDiscardBuffer=FALSE
09:28:08.454 SIP.STACK DEBUG TRANSMITTER TransmitterControlTransmitMessage - pTrx=0x526dca8: A message was successfully sent over UDP.
09:28:08.454 SIP.STACK DEBUG TRANSMITTER TransmitterChangeState - transmitter 0x526dca8 state changed: Ready For Sending->Msg Sent, (reason = Undefined)
09:28:08.454 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526dca8 - Before callback
09:28:08.454 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x527a480: Setting timers
09:28:08.455 SIP.STACK DEBUG TRANSACTION UDPTimersDecide - Transaction 0x527a480: state=Client General Request Sent, Decisions: (*bSetMainTimer=1, *mainTimerInterval=500, *bSetLongReqestTimer=1, *longTimerInterval=32000
09:28:08.455 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=527a570; event=3f5f028)
09:28:08.455 SIP.STACK DEBUG TRANSACTION TransactionTimerSetTimers - Transaction 0x527a480: timer was set to 500 milliseconds
09:28:08.455 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=527a590; event=3f5f0c8)
09:28:08.456 SIP.STACK DEBUG TRANSACTION TransactionTimerSetTimers - Transaction 0x527a480: long timeout timer was set to 32000 milliseconds
09:28:08.456 SIP.STACK DEBUG TRANSMITTER TransmitterCallbackStateChangeEv: Transmitter 0x526dca8,After callback
09:28:08.456 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a480, Before callback
09:28:08.456 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a480,After callback
09:28:08.456 SIP.STACK DEBUG TRANSACTION SipTransactionRequest - Transaction 0x527a480: Request was sent successfully
09:28:08.457 SIP.STACK DEBUG REG_CLIENT RegClientChangeState - Register-client 0x5311550 state changed: Unauthenticated->Registering, (reason = User request)
09:28:08.457 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x5311550, Before callback
09:28:08.457 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x5311550,After callback
09:28:08.457 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x5311550,After callback
09:28:08.457 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a278,After callback
09:28:08.458 SIP.STACK DEBUG TIMER RvTimerStart: event allocated(tqueue=3ddd6b4; timer=527a368; event=3f5f078)
09:28:08.458 SIP.STACK DEBUG TRANSACTION TransactionStateUacGeneralFinalResponseRcvd - Transaction 0x527a278: timer 0x527a368 was set to 5000 milliseconds
09:28:08.458 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3cea3b0 After callback
09:28:08.458 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3cea390) (MessagePool)
09:28:08.516 SIP.STACK DEBUG SELECT Occured event: fd=27,event=Read ,error=0
09:28:08.517 SIP.STACK DEBUG TRANSPORT TransportMgrAllocateRcvBuffer - Successfully allocated buffer 0x49760e8
09:28:08.517 SIP.STACK DEBUG TRANSPORT TransportUdpEventCallback - sock 27: Recv new UDP message. 172.16.30.40:5060<-75.98.50.46:5060, size=518
09:28:08.517 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - MESSAGE_RCVD_EVENT 0x4018160, buffer 0x49760e8
09:28:08.517 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - MESSAGE_RCVD_EVENT 0x4018160, buffer 0x49760e8
09:28:08.518 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=518 Before callback
09:28:08.518 SIP.STACK DEBUG TRANSPORT TransportCallbackBufferReceived: bDiscardBuffer=FALSE, Local Addrs (172.16.30.40:5060,UDP), Remote Addrs (75.98.50.46:5060,UDP), hConn=0x0, buffLen=518 After callback
09:28:08.518 SIP.STACK DEBUG RPOOL RPOOL_GetPage - (pool=0x3b9f010,size=0,*newRpoolElem=0x3cf0590)=0 (MessagePool)
09:28:08.519 SIP.STACK DEBUG MESSAGE RvSipMsgConstruct - Got a new page. hPage is 0x3cf0590.
09:28:08.519 SIP.STACK DEBUG MESSAGE RvSipViaHeaderSetCompactForm - Setting compact form of Header 0x3cf0610 to 0
09:28:08.519 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3cf06e0 to 0
09:28:08.520 SIP.STACK DEBUG MESSAGE RvSipPartyHeaderSetCompactForm - Setting compact form of Header 0x3cf07c0 to 0
09:28:08.521 SIP.STACK DEBUG MESSAGE RvSipContactHeaderSetCompactForm - Setting compact form of hHeader 0x3cf0948 to 0
09:28:08.521 SIP.STACK DEBUG RPOOL RPOOL_Append - (pool=0x3b9f010,element=0x3cf0590,size=16,consecutiveMemory=1,*AllocationOffset=0x600) new block appended (MessagePool)
09:28:08.521 SIP.STACK DEBUG MESSAGE RvSipMsgSetContentLengthCompactForm - Setting compact form of Content-Length for hMsg 0x3cf05b0 to 0
09:28:08.522 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3cf05b0: Before callback
09:28:08.522 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3cf07f8
09:28:08.522 SIP.STACK DEBUG MESSAGE RvSipAddrUrlGetUser - Getting user of address 0x3cf0718
09:28:08.522 SIP.STACK DEBUG TRANSPORT TransportCallbackMsgReceivedEv - hMsg=0x3cf05b0: After callback, bProcessMsg = 1
09:28:08.523 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3cf05b0 Before callback (bsAction=Continue)
09:28:08.523 SIP.STACK DEBUG TRANSACTION HandleIncomingResponseMsg - A response msg 0x3cf05b0- starting to process...
09:28:08.523 SIP.STACK DEBUG TRANSACTION HashKeyMethodsAreEqual - Methods are equal (REGISTER)
09:28:08.523 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x527a480, Before callback
09:28:08.524 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgReceivedEv: Register-client 0x5311550, Before callback
09:28:08.524 SIP.STACK DEBUG REG_CLIENT RegClientCallbackMsgReceivedEv: Register-client 0x5311550,After callback
09:28:08.524 SIP.STACK DEBUG TRANSACTION TransactionCallBackMsgReceivedEv: Transc 0x527a480,After callback (rv=0)
09:28:08.524 SIP.STACK DEBUG TRANSACTION TransactionTimerReleaseAllTimers - Transaction 0x527a480: Timeout timer was released
09:28:08.525 SIP.STACK DEBUG TRANSACTION TransactionTimerMainTimerRelease - Transaction 0x527a480: Timer 0x527a570 was released
09:28:08.525 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a480, Before callback
09:28:08.525 SIP.STACK DEBUG TRANSACTION RvSipTransactionGetReceivedMsg - transc= 0x527a480 returned handle= 0x3cf05b0
09:28:08.525 SIP.STACK DEBUG REG_CLIENT RegClientChangeState - Register-client 0x5311550 state changed: Registering->Registered, (reason = Response succeessful received)
09:28:08.525 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x5311550, Before callback
09:28:08.526 SIP.STACK DEBUG TRANSACTION SipTransactionDetachOwner - transc 0x527a480, calling TransactionNoOwner()
09:28:08.526 SIP.STACK DEBUG TRANSACTION SipTransactionDetachOwner - Transaction 0x527a480: Detached successfully
09:28:08.526 SIP.STACK DEBUG TRANSACTION TransactionTerminate - Transaction 0x527a480: Termination called
09:28:08.526 SIP.STACK DEBUG TRANSACTION TransactionTransportDetachAllConnections - Transaction 0x527a480: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)
09:28:08.527 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - pObj=0x527a480,pEventInfo=0x527a480,eNum=0,bInternal=1
09:28:08.527 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - INTERNAL_EVENT ev=0x40181a8: Transaction 0x527a480: Terminated
09:28:08.527 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - ev 0x40181a8 sent. (Transaction 0x527a480: Terminated)
09:28:08.527 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - pObj=0x5311550,pEventInfo=0x5311550,eNum=0,bInternal=1
09:28:08.527 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - INTERNAL_EVENT ev=0x40181f0: Reg-Client 0x5311550: Terminated
09:28:08.528 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - ev 0x40181f0 sent. (Reg-Client 0x5311550: Terminated)
09:28:08.528 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x5311550,After callback
09:28:08.528 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a480,After callback
09:28:08.528 SIP.STACK DEBUG TRANSACTION TransactionStateUacGeneralFinalResponseRcvd - Transaction 0x527a480: was terminated from callback - timers are not set
09:28:08.529 SIP.STACK DEBUG MSGBUILDER TransportCallbackMsgRcvdEv: Msg 0x3cf05b0 After callback
09:28:08.529 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3cf0590) (MessagePool)
09:28:08.529 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - INTERNAL_EVENT ev:0x40181a8, (Transaction 0x527a480: Terminated)
09:28:08.529 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a480, Before callback
09:28:08.529 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a480,After callback
09:28:08.530 SIP.STACK DEBUG TRANSACTION TransactionDestruct - Transaction 0x527a480: start to destruct transaction
09:28:08.530 SIP.STACK DEBUG TRANSACTION TransactionTransportDetachAllConnections - Transaction 0x527a480: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)
09:28:08.530 SIP.STACK DEBUG TRANSMITTER TransmitterDestruct - transmitter 0x526dca8 destructing...
09:28:08.530 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3cee0d0) (MessagePool)
09:28:08.530 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e09e90) (GeneralPool)
09:28:08.531 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - INTERNAL_EVENT ev:0x40181f0, (Reg-Client 0x5311550: Terminated)
09:28:08.531 SIP.STACK DEBUG REG_CLIENT RegClientChangeState - Register-client 0x5311550 state changed to Terminated, (reason = User request)
09:28:08.531 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x5311550, Before callback
09:28:08.531 SIP.STACK DEBUG REG_CLIENT RegClientCallbackStateChangeEv: Register-client 0x5311550,After callback
09:28:08.532 SIP.STACK DEBUG AUTH SipAuthenticatorAuthenticationHeaderFree - Free Authentication header
09:28:08.532 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e09650) (GeneralPool)
09:28:08.532 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e05c90) (GeneralPool)
09:28:13.458 SIP.STACK DEBUG TIMER RvTimerQueueService: timer expired(tqueue=3ddd6b4; event=3f5f078)
09:28:13.458 SIP.STACK DEBUG TRANSPORT TransportMultiThreadTimerEventHandler - Allocating timer expired event
09:28:13.459 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - TIMER_EXPIRED_EVENT 0x4018238
09:28:13.459 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - TIMER_EXPIRED_EVENT 0x4018238
09:28:13.459 SIP.STACK DEBUG TIMER RvTimerQueueService: timer expired(tqueue=3ddd6b4; event=3f5f078)
09:28:13.459 SIP.STACK DEBUG TRANSACTION TransactionTimerHandleMainTimerTimeout - Transaction 0x527a278: timer expired (transc state=Client General Final Response Rcvd)
09:28:13.460 SIP.STACK DEBUG TRANSACTION TransactionTerminate - Transaction 0x527a278: Termination called
09:28:13.460 SIP.STACK DEBUG TRANSACTION TransactionTransportDetachAllConnections - Transaction 0x527a278: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)
09:28:13.460 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - pObj=0x527a278,pEventInfo=0x527a278,eNum=10,bInternal=1
09:28:13.460 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueTailEvent - INTERNAL_EVENT ev=0x4018280: Transaction 0x527a278: Terminated
09:28:13.461 SIP.STACK DEBUG TRANSPORT SipTransportSendObjectEvent - ev 0x4018280 sent. (Transaction 0x527a278: Terminated)
09:28:13.461 SIP.STACK DEBUG TRANSPORT TransportProcessingQueueDispatchEvents - INTERNAL_EVENT ev:0x4018280, (Transaction 0x527a278: Terminated)
09:28:13.461 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a278, Before callback
09:28:13.461 SIP.STACK DEBUG TRANSACTION TransactionCallbackStateChangedEv: Transc 0x527a278,After callback
09:28:13.461 SIP.STACK DEBUG TRANSACTION TransactionDestruct - Transaction 0x527a278: start to destruct transaction
09:28:13.462 SIP.STACK DEBUG TRANSACTION TransactionTransportDetachAllConnections - Transaction 0x527a278: All connections will be detached: (Active:0x0, Inv backup: 0x0, Resp backup = 0x0)
09:28:13.462 SIP.STACK DEBUG TRANSMITTER TransmitterDestruct - transmitter 0x526df80 destructing...
09:28:13.462 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3b9f010,element=0x3ce7ed0) (MessagePool)
09:28:13.462 SIP.STACK DEBUG RPOOL RPOOL_FreePage - (pool=0x3dde010,element=0x3e064d0) (GeneralPool)
Thomas,
I am not seeing all the debug. Can you make sure you buffer is big enough on your telnet/ssh session to capture it all.
ALso, what adtran are you using and what firmware?
Are you using SRTP and TLS?
can you also do a "show debug" so i can see what debugs you entered.
Thanks
Model; TA908e
Firmware: R12.3.0.SA.E
SRTP / TLS: No
Mark,
As soon as I enter the debug, we start getting a ton of data across the terminal screen.
Not sure where to start/stop.
A lot of data is being displayed before and after call.
Would probably be easier if you logged in and looked for yourself.
Thomas Luksa
Landstar Telecom