- Cisco Community
- Technology and Support
- Collaboration
- IP Telephony and Phones
- C3825 as SIP-to-SIP Gateway doesn't work.
- Subscribe to RSS Feed
- Mark Topic as New
- Mark Topic as Read
- Float this Topic for Current User
- Bookmark
- Subscribe
- Mute
- Printer Friendly Page
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-25-2013 06:56 AM - edited 03-16-2019 06:04 PM
I tried to setup Cisco 3825 as SIP-toSIP GW between customer's Voice Gateway (Quintum AXF, 80.251.131.27) and "RTU" Soft-Switch (cluster's IPs: 80.251.131.132 and 80.251.131.133 and internal ones 10.0.99.121, 10.0.99.221 and 10.0.99.99 - shared Heartbeat IP).
When I connect Quintum directly to RTU (making corresponding settings on RTU and Quintum) - all works fine! The matter is not in Quintum or in RTU. This is verfied.
Cisco3825 (80.251.131.28) accepts SIP INVITEs and sends ones on the same interface (one interface configuration what is "highly recommended"). But it doesn't help. Call looks like in the following trace got on RTU (10.0.99.111 is my phone for simplification):
17:44:50.930821 10.0.99.111 -> 10.0.99.99 SIP/SDP Request: INVITE sip:4996540908@10.0.99.99;user=phone, with session description
17:44:50.933458 10.0.99.99 -> 10.0.99.111 SIP Status: 100 Trying
17:44:50.957366 80.251.131.132 -> 80.251.131.28 SIP/SDP Request: INVITE sip:0008014996540908@80.251.131.28;user=phone, with session description
17:44:50.976924 80.251.131.28 -> 80.251.131.132 SIP Status: 100 Trying
17:44:51.534246 80.251.131.28 -> 80.251.131.132 SIP/SDP Status: 183 Session Progress, with session description
17:44:51.535698 10.0.99.99 -> 10.0.99.111 SIP/SDP Status: 183 Progress, with session description
17:44:51.596882 80.251.131.28 -> 80.251.131.132 SIP Status: 503 Service Unavailable
17:44:51.597308 80.251.131.132 -> 80.251.131.28 SIP Request: ACK sip:0008014996540908@80.251.131.28;user=phone
17:44:51.598557 10.0.99.99 -> 10.0.99.111 SIP Status: 503 Service Unavailable
17:44:51.599091 10.0.99.111 -> 10.0.99.99 SIP Request: ACK sip:4996540908@10.0.99.99;user=phone
This trace has been got from RTU side. At the moment when 183 Session Progress is coming on the phone connected to Quintum's analogue port one ring is heard (single). When 503 Service Unavailable is coming I get short rings on my phone, Quintum's Phone become silent, because Quintum judging on its traces gets CANCEL from Cisco.
I have tried a handful of IOSes, with "T" of without it, but effect is always much the same.
How-to? Help, please!... :-)
Router#sh run
Building configuration...
Current configuration : 3109 bytes
!
! Last configuration change at 12:25:08 UTC Tue Jun 25 2013 by eyatsko
!
version 15.1
service timestamps debug datetime msec
service timestamps log datetime msec
service password-encryption
!
hostname Router
!
boot-start-marker
boot system flash:/c3825-adventerprisek9-mz.151-3.T2.bin
boot system flash:/c3825-adventerprisek9-mz.124-24.T2.bin
boot system flash:/c3825-adventerprisek9_ivs_li-mz.124-24.T2.bin
boot system flash:/c3825-advipservicesk9-mz.151-3.T2.bin
boot-end-marker
!
! card type command needed for slot/vwic-slot 0/0
!
no aaa new-model
!
!
dot11 syslog
ip source-route
!
ip cef
!
!
no ipv6 cef
!
multilink bundle-name authenticated
!
!
voice-card 0
!
!
voice service voip
ip address trusted list
ipv4 80.251.131.128 255.255.255.224
allow-connections sip to sip
sip
!
!
voice class uri RTU1 sip
host 80\.251\.131\.132
!
voice class uri RTU2 sip
host 80\.251\.131\.133
!
voice class codec 1
codec preference 1 g711alaw
!
!
voice translation-rule 801
rule 1 /^000801\(.*\)$/ /\1/
!
voice translation-profile 801
translate called 801
!
crypto pki token default removal timeout 0
!
license udi pid CISCO3825 sn FHK0903F413
archive
log config
hidekeys
username eyatsko privilege 15 password 7 0322531D001A354042030056
!
redundancy
!
interface GigabitEthernet0/0
no ip address
duplex auto
speed auto
media-type rj45
!
interface GigabitEthernet0/0.16
encapsulation dot1Q 16
ip address 80.251.131.28 255.255.255.240
!
interface GigabitEthernet0/0.18
encapsulation dot1Q 18
ip address 10.0.99.34 255.255.255.0
shutdown
!
interface GigabitEthernet0/1
no ip address
shutdown
duplex auto
speed auto
media-type rj45
!
ip forward-protocol nd
!
!
no ip http server
no ip http secure-server
ip route 0.0.0.0 0.0.0.0 80.251.131.17
!
logging esm config
!
!
control-plane
!
mgcp profile default
!
dial-peer voice 801 voip
translation-profile outgoing 801
huntstop
destination-pattern 000801.+
session protocol sipv2
session target ipv4:80.251.131.27
dtmf-relay rtp-nte
codec transparent
fax-relay ecm disable
fax rate 9600
fax protocol t38 version 0 ls-redundancy 5 hs-redundancy 2 fallback none
no vad
!
dial-peer voice 901 voip
modem passthrough nse codec g711alaw
session protocol sipv2
incoming called-number .+
incoming uri from RTU1
dtmf-relay rtp-nte
codec transparent
fax-relay ecm disable
fax rate 9600
fax protocol t38 version 0 ls-redundancy 5 hs-redundancy 2 fallback none
no vad
!
dial-peer voice 902 voip
shutdown
modem passthrough nse codec g711alaw
session protocol sipv2
incoming called-number .+
incoming uri from RTU2
dtmf-relay rtp-nte
codec transparent
fax-relay ecm disable
fax rate 9600
fax protocol t38 version 0 ls-redundancy 5 hs-redundancy 2 fallback none
no vad
!
!
line con 0
exec-timeout 1440 0
logging synchronous
login local
line aux 0
line vty 0 4
exec-timeout 1440 0
logging synchronous
login local
transport input all
line vty 5 15
exec-timeout 1440 0
logging synchronous
login local
transport input all
!
scheduler allocate 20000 1000
end
Router#
Kind regards,
Ellad Yatsko
Solved! Go to Solution.
- Labels:
-
Other IP Telephony
Accepted Solutions
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-26-2013 11:12 AM
I think the issue here is the Invite from CUCM doesn't have 100rel supported but the outbound Invite to the PSTN does so the PSTN sends a 183 Session Progress with SDP. The CUBE knows CUCM can't handle this and therefor sends the Cancel with cause code 47. There's 2 ways to fix this. You can either enable Prack in the CUCM SIP Profile under SIP Rel1XX Options. You can set this to Send Prack if 1xx Contains SDP. That way CUCM will send rel1xx as supported in its outgoing Invite to the CUBE and thus the CUBE will forward the 183 Session Progress appropriately and get a PRACK back from CUCM. The other option would be disabling outbound rel1xx advertisement on the CUBE. You can do this on the outbound dial-peer by running "voice-class sip rel1xx disable".
Thanks,
Brian Meade
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-25-2013 07:17 AM
Can you send the debiug ccsip messages from the CUBE gateway. Include calling and called number
Please rate all useful posts
"opportunity is a haughty goddess who waste no time with those who are unprepared"
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-25-2013 07:26 AM
499654000 -> (000801)4996540908. Where "000801" is Tech Prefix.
Router#debug ccsip all
This may severely impact system performance. Continue? [confirm]
All SIP Call tracing is enabled
Router#
//17/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x68C0CFF8, addr=80.251.131.27, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x61B5D640
//17/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//17/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x715B8E40,addr=80.251.131.27
//-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnHolder: Created new holder=0x715B8E40, addr=80.251.131.27; nailed=FALSE
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for addr=80.251.131.27, port=5060, context=0x70771354
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for connection=0x70772D48,addr=80.251.131.27, port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer:
Wait Conn Timer started for 5000 msec
//-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new initiated conn=0x70772D48, connid=-1, addr=80.251.131.27, port=5060, local_addr=, transport=UDP
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.27, rport:5060 with laddr:
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x7136D548 with connection=0x70772D48
//17/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Deferred sending msg=0x68C0CFF8
//16/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>
Date: Tue, 25 Jun 2013 13:24:28 GMT
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 59
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWConnectionCreated: context=0x70771354
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: gConnTab=0x70771354, addr=80.251.131.27, port=5060, local_addr=, connid=3, transport=UDP
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessConnCreated: connection instance created for addr:80.251.131.27, port:5060 local_addr= local_port=56928
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportStopConnWaitTimer: Wait timer stopped for connection=0x70772D48,addr=80.251.131.27, port=5060
//-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceHandleConnectionCreated: Moving connection=0x70772D48, connid=3 state to established. local_addr=, local_port=56928
//17/6CD13618A62E/SIP/Transport/sipTransportPostInternalMsg: Posting Internal Msg type=0
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.132]:5061, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.132]:5061, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 64
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x68C0CFF8, addr=80.251.131.27, port=5060, local_addr=, connId=3 for UDP
//17/6CD13618A62E/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE
//-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued.
//17/6CD13618A62E/SIP/State/sipSPIChangeState: 0x7136D548 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_SENT_INVITE, SUBSTATE_NONE)
//17/6CD13618A62E/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 17) to the VOIP RTP library
//17/6CD13618A62E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
//17/6CD13618A62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
//17/6CD13618A62E/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
//17/6CD13618A62E/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 80.251.131.28, lport = 16584, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE
src_callid = 17, dest_callid = -1, stream type = voice+dtmf, stream direction = RECVONLY
media_ip_addr = - , vrf tableid = 0 media_addr_type = 1
//17/6CD13618A62E/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
//17/6CD13618A62E/SIP/Info/sipSPICreateRtpSession: sess: 715B8D2C do_rtcp:0
//16/6CD13618A62E/SIP/Info/ccsip_update_peer_caps: gccb/stream is NULL, not updating now !!
//17/6CD13618A62E/SIP/Info/sipSPIUpdateGccb: Failure from the peer leg so no updations now!!
//17/6CD13618A62E/SIP/Media/sipSPICreateRtpSession: stun is disabled
//17/6CD13618A62E/SIP/State/sipSPIChangeStreamState: Stream (callid = 17) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
//17/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:4996540908@80.251.131.27:5060 SIP/2.0
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
Remote-Party-ID: <4996540000>;party=calling;screen=yes;privacy=off
From: <4996540000>;tag=87F4E4-19DE
To: <4996540908>
Date: Tue, 25 Jun 2013 13:24:28 GMT
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 1825650200-3718386146-2788032538-1690784136
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Timestamp: 1372166668
Contact: <4996540000>
Expires: 180
Allow-Events: telephone-event
Max-Forwards: 69
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 365
v=0
o=CiscoSystemsSIP-GW-UserAgent 7548 722 IN IP4 80.251.131.28
s=SIP Call
c=IN IP4 80.251.131.28
t=0 0
m=audio 16584 RTP/AVP 8 0 18 4 101
c=IN IP4 80.251.131.28
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=fmtp:4 bitrate=6.3;annexa=yes
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:0008014996540908@80.251.131.28;user=phone SIP/2.0
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Contact: <4996540000>
Content-Type: application/sdp
Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, REFER, REGISTER, UPDATE
Max-Forwards: 70
User-Agent: MERA MVTS3G v.4.4.0-15
Cisco-Guid: 1825650200-3718386146-2788032538-1690784136
Remote-Party-ID: <4996540000>;party=calling;privacy=off;screen=yes
Content-Length: 319
v=0
o=- 1372170045 1372170045 IN IP4 80.251.131.133
s=-
c=IN IP4 80.251.131.133
t=0 0
m=audio 17254 RTP/AVP 8 0 18 4 96
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=fmtp:4 annexa=yes
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//16/6CD13618A62E/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x7137DCA0
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.132,Port 5061, Transport 1, SentBy Port 5060
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.132,Port 5061, Transport
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x6197CB18z 0x61983A58z 0x618F5CB8z 0x61934F50z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z 1, SentBy Port 5061
//16/6CD13618A62E/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: , current remote number: 4996540000
//16/6CD13618A62E/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00
//16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
//16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, container:710FD024
//16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing
//16/6CD13618A62E/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 3 event
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//16/6CD13618A62E/SIP/Info/sipSPISendInviteResponse: Associated container=0x710FD024 to Invite Response 100
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x6A567768, addr=80.251.131.132, port=5061, sentBy_port=5061, local_addr=, is_req=0, transport=1, switch=0, callBack=0x0
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x6A567768 to default port=5061
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection requ
%SYS-3-CPUHOG: Task is running for (4004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB364z 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61B64870z 0x61B65408z 0x61B66210z 0x619220D8z 0x61922618z 0x619351B8z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z ired for raddr:80.251.131.132, rport:5061 with laddr:
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x6A567768
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x6A567768, addr=80.251.131.132, port=5061, local_addr=, connId=2 for UDP
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//16/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>
Date: Tue, 25 Jun 2013 13:24:36 GMT
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:0008014996540908@80.251.131.28;user=phone SIP/2.0
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Contact: <4996540000>
Content-Type: application/sdp
Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, REFER, REGISTER, UPDATE
Max-Forwards: 70
User-Agent: MERA MVTS3G v.4.4.0-15
Cisco-Guid: 1825650200-3718386146-2788032538-1690784136
Remote-Party-ID: <4996540000>;party=calling;privacy=off;screen=yes
Content-Length: 319
v=0
o=- 1372170045 1372170045 IN IP4 80.251.131.133
s=-
c=IN IP4 80.251.131.133
t=0 0
m=audio 17254 RTP/AVP 8 0 18 4 96
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=fmtp:4 annexa=yes
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//16/6CD13618A62E/SIP/Info/sipSPIFindCcbUASReqTable: *****CCB found in UAS Request table. ccb=0x7137DCA0
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.132,Port 5061, Transport 1, SentBy Port 5060
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.132,Port 5061, Transport
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB374z 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x6197CB18z 0x61983A58z 0x618F5CB8z 0x61934F50z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z 1, SentBy Port 5061
//16/6CD13618A62E/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: , current remote number: 4996540000
//16/6CD13618A62E/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00
//16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
//16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, container:710FD444
//16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing
//16/6CD13618A62E/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 3 event
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//16/6CD13618A62E/SIP/Info/sipSPISendInviteResponse: Associated container=0x710FD444 to Invite Response 100
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x68C0F95C, addr=80.251.131.132, port=5061, sentBy_port=5061, local_addr=, is_req=0, transport=1, switch=0, callBack=0x0
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x68C0F95C to default port=5061
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection req
%SYS-3-CPUHOG: Task is running for (4004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB374z 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61B64870z 0x61B65408z 0x61B66210z 0x619220D8z 0x61922618z 0x619351B8z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z uired for raddr:80.251.131.132, rport:5061 with laddr:
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x68C0F95C
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x68C0F95C, addr=80.251.131.132, port=5061, local_addr=, connId=2 for UDP
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//17/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 183 Session Progress
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Content-Length: 225
Content-Type: application/sdp
CSeq: 101 INVITE
From: <4996540000>;tag=87F4E4-19DE
Require: 100rel
RSeq: 7000
To: <4996540908>;tag=50fb831b-96
User-Agent: Quintum/1.0.0 SN/0030E1103326
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
Quintum: 070e0000000c00000006001e03808081
v=0
o=Quintum 78 722 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10334 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
a=sendrecv
//17/6CD13618A62E/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
//17/6CD13618A62E/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
//17/6CD13618A62E/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 10334
SIP: Attribute mid, level 1 instance 1 not found.
//17/6CD13618A62E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
//17/6CD13618A62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
//-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96
//-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB368z 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61AB0BC4z 0x61AB0C54z 0x61AB0E98z 0x61AB7284z 0x61ABE5C4z 0x61A5DAA0z 0x6192DAA0z 0x61943318z 0x6194D918z 0x6194E0BCz as its in use by other codec No Codec
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:
//17/6CD13618A62E/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1
//17/6CD13618A62E/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
//-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160
//-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
//17/6CD13618A62E/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711alaw
//17/6CD13618A62E/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0
//17/6CD13618A62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
//-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec
//-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
//17/6CD13618A62E/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE
//17/6CD13
%SYS-3-CPUHOG: Task is running for (4004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB364z 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61AB1FC8z 0x61AB25C0z 0x61AB7B20z 0x61ABE5C4z 0x61A5DAA0z 0x6192DAA0z 0x61943318z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 618A62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
//17/6CD13618A62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events.
//-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0
//17/6CD13618A62E/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
//17/6CD13618A62E/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
//17/6CD13618A62E/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=rtp-nte
stream_type=voice+dtmf (1), dest_ip_address=80.251.131.27, dest_port=10334
//17/6CD13618A62E/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
//17/6CD13618A62E/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
//17/6CD13618A62E/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
//17/6CD13618A62E/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's Flow Around
//17/6CD13618A62E/SIP/Media/sipSPIUpdCallWithSdpInfo:
Preferred Codec : g711alaw, bytes :160
Preferred DTMF relay : rtp-nte
Preferred NTE payload : 101
Early Media : No
Delayed Media : No
Bridge Done : No
New Media : No
DSP DNLD Reqd : No
//17/6CD13618A62E/SIP/Info/resolve_media_ip_address_to_bin
%SYS-3-CPUHOG: Task is running for (6004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB368z 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61AEB9F8z 0x61A93AC0z 0x61A9414Cz 0x61A5DE5Cz 0x6192DAA0z 0x61943318z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z d: Media already bound, use existing source_media_ip_addr
//17/6CD13618A62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 17 peer 16 flags 0x400045 state STATE_SENT_INVITE
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_vcc_ProcessXcoderNeeded: xcoder_attached not yet initialised for this call.
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Xcoder not yet used for the call
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 17, Peer CallID 16, sdp 0x68C0D110 channels 0x7136EAE4
//17/6CD13618A62E/SIP/Info/copy_channels:
callId 17 size 924 ptr 0x68C125CC)
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB t38 version 0 ipip_caps version 0
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB fax rate 32 ipip_caps rate 9600
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: reset the switch..
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 8 mline 1
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw
//17/6CD13618A62E/SIP/Info/codec_found:
Codec to be matched: 6
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6
//-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
//1
%SYS-3-CPUHOG: Task is running for (8008)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x619E8AD4z 0x619EB41Cz 0x61A94304z 0x61A5DE5Cz 0x6192DAA0z 0x61943318z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 7/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 6 ptype 8 time 20, bytes 160 as channel 0 mline 1 ss 1 80.251.131.27:10334
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 101 mline 1
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 17, dtmf = 6
//17/6CD13618A62E/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: Unable to find the proper instance for FMTP
SIP: fmtp attribute, level 1 instance 0 not found.
//17/6CD13618A62E/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: Unable to acquire event mask for rfc2833 dtmf relay
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 6
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Updating tagdata..
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 17 flags 0x10000100 state STATE_SENT_INVITE
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0x440018, ccb->pld.flags_ipip 0x400045
//17/6CD13618A62E/SIP/Info/s
%SYS-3-CPUHOG: Task is running for (10004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x619EED50z 0x61A94304z 0x61A5DE5Cz 0x6192DAA0z 0x61943318z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z ipSPI_ipip_report_media_to_peer: Updating the negotiated codec bytes
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Post CAPS to peer.
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_caps_ind_internal:
destCallID=16, srcCallID=17,
peer_ccb->call_info.currentLocalName=,
peer_ccb->call_info.currentRemoteName=,
ccb->call_info.currentLocalName=,
ccb->call_info.currentRemoteName=
//16/6CD13618A62E/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=-1, current_seq_num=0x13B4
//16/6CD13618A62E/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=-1, current_seq_num=0x0
//16/6CD13618A62E/SIP/Info/ccsip_update_stream_negotiated_codec: Codec that peer call leg has indicated is same what this call leg is already using.. Do nothing..
//16/6CD13618A62E/SIP/Info/ccsip_caps_ind_internal: Load DSP with negotiated codec: g711alaw, Bytes=160
//16/6CD13618A62E/SIP/Info/ccsip_caps_ind_internal: Set forking flag to 0x0
//16/6CD13618A62E/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 96, tx payload = 96
//16/6CD13618A62E/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
//16/6CD13618A62E/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=17
//16/6CD13618A62E/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
//16/6CD13618A62E/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
//16/6CD13618A62E/S
%SYS-3-CPUHOG: Task is running for (12004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB364z 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61ACC360z 0x619A9518z 0x619ABCB0z 0x617D27C4z 0x619EEE8Cz 0x61A94304z 0x61A5DE5Cz 0x6192DAA0z 0x61943318z 0x6194D918z IP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
//16/6CD13618A62E/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
//16/6CD13618A62E/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=2, redundancy=0, xid=0, relay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
//16/6CD13618A62E/SIP/Media/sipSPISetStreamInfo: 0 Active Streams
//16/6CD13618A62E/SIP/Media/sipSPISetStreamInfo: Number of active streams is zero (0)!
//16/6CD13618A62E/SIP/Media/sipSPISetStreamInfo:
caps.stream_count=0,caps.stream[0].stream_type=0xFFFF, caps.stream_list.xmitFunc=
//16/6CD13618A62E/SIP/Media/sipSPISetStreamInfo: ??unknown??, caps.stream_list.context=
//16/6CD13618A62E/SIP/Media/sipSPISetStreamInfo: 0x0 (gccb)
//16/6CD13618A62E/SIP/Info/ccsip_caps_ind_internal: Load DSP with codec : g711alaw, Bytes=160, payload = 0
//16/6CD13618A62E/SIP/Info/ccsip_caps_ind_internal: ccsip_caps_ind: ccb->pld.flags_ipip = 0x400443
//16/6CD13618A62E/SIP/Info/sipSPISrtpTranscoder:
Checking if transcoder is needed for SRTP-RTP
//16/6CD13618A62E/SIP/Info/ccsip_caps_ind_internal: No video caps detected in the caps posted by peer leg
//16/6CD13618A62E/SIP/Info/ccsip_caps_ind_internal: Calling cc_api_caps_ack()
//17/6CD13618A62E/SIP/Info/ccsip_caps_ack_internal: Set forking flag to 0x0
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0x440018, ccb->pld.flags_ipip 0x400045
//17/6CD13618A62E/SIP/Info/copy_channels:
callId 17 size 240 ptr 0x68C1D1DC)
//-1/xxxxxxxxxxxx/SIP/In
%SYS-3-CPUHOG: Task is running for (14008)msecs, more than (2000)msecs (2/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x6199E7FCz 0x6178E4B4z 0x619EF0ACz 0x61A94304z 0x61A5DE5Cz 0x6192DAA0z 0x61943318z 0x6194D918z 0x6194E0BCz 0x61AE3D68z fo/ccsip_event_handler: switch(ev.ev_id: 165)
//16/6CD13618A62E/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 17 chans 0x68C1D1DC event 165 flags 0x40001C 0x10000140 0x400443 data 0x68C1D1DC
//16/6CD13618A62E/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_OPEN_CHANNEL_IND: peer ID 17 chans 0x68C1D1DC event 165 flags 0x40001C 0x10000140 0x400443 data 0x68C1D1DC
//-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_NEW_MEDIA
//16/6CD13618A62E/SIP/Info/ccsip_event_handler:
ccsip_event_handler: set event->type = SIPSPI_EV_CC_NEW_MEDIA!: peer ID 17 chans 0x68C1D1DC event 165 flags 0x40001C 0x10000140 0x400443 data 0x68C1D1DC Media Trigger 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: SIP2SIP, posting channel_ind to peer.
//17/6CD13618A62E/SIP/Info/ccsip_update_srtp_caps: 7392: Not Sending NULL SRTP CAPS to SIP LEG
//17/6CD13618A62E/SIP/Media/sipSPIUpdCallWithSdpInfo:
Stream type : voice+dtmf
Media line : 1
State : STREAM_ADDING (2)
Stream address type : 1
Callid : 17
Negotiated Codec : g711alaw, bytes :160
Nego. Codec payload : 8 (tx), 8 (rx)
Negotiated DTMF relay : rtp-nte
Negotiated NTE payload : 101 (tx), 101 (rx)
Negotiated CN payload : 0
Media Srce Addr/Port : [80.251.131.28]:16584
Media Dest Addr/Port : [80.251.131.27]:10334
//17/6CD13618A62E/SIP/Info/sipSPIProcessHistoryInfoHeader:
%SYS-3-CPUHOG: Task is running for (16004)msecs, more than (2000)msecs (2/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB374z 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61B0B18Cz 0x61A5DFC0z 0x6192DAA0z 0x61943318z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z No HI headers recvd from app container
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
//-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
//17/6CD13618A62E/SIP/Error/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 0
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
//17/6CD13618A62E/SIP/Error/ccsip_api_call_cut_progress: Unable to add headers
into container
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 100)
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
//17/6CD13618A62E/SIP/Info/HandleSIP1xxSessionProgress: ccsip_api_call_cut_progress returned: SIP_SUCCESS
//17/6CD13618A62E/SIP/State/sipSPIChangeState: 0x7136D548 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_NONE)
//17/6CD13618A62E/SIP/Error/sipSPIRel1xxCheck: Error in Contact/RR query launch in 18x
//17/6CD13618A62E/SIP/Info/ccsip_set_cc_cause_for_spi_err: Categorized cause:47, category:180
//17/6CD13618A62E/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[17], src[6]
//17/6CD13618A62E/SIP/Info/sipSPIPr
%SYS-3-CPUHOG: Task is running for (18004)msecs, more than (2000)msecs (2/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61B152BCz 0x6191B4E0z 0x618EA360z 0x61943318z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z esendProcessing: Presend Processing called for 3 event
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//17/6CD13618A62E/SIP/Info/sipSPISendCancel: Associated container=0x710FCC5C to Cancel
//17/6CD13618A62E/SIP/Transport/sipSPISendCancel: Sending CANCEL to the transport layer
//17/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x68C1D300, addr=80.251.131.27, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x61B5EE7C
//17/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//17/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.27, rport:5060 with laddr:
//17/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x68C1D300
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x68C1D300, addr=80.251.131.27, port=5060, local_addr=, connId=3 for UDP
//17/6CD13618A62E/SIP/Info/sentCancelInitiateDisconnect: Sent Cancel Request, starting CancelWaitResponseTimer
//17/6CD13618A62E/SIP/Info/sipSPIInitiateDisconnect: Initiate call disconnect(47) for outgoing call
//-1/xxxxxxxxxxxx/SIP/Error/sipSPIGetContentQSIG: No Inbound Container Created !!!
//-1/xxxxxxxxxxxx/SIP/Error/sipSPIGetContentQ931: No Inbound Container
%SYS-3-CPUHOG: Task is running for (20004)msecs, more than (2000)msecs (2/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB374z 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61978A8Cz 0x61AF11ACz 0x61A66028z 0x618EAAD8z 0x61B66228z 0x6191BB34z 0x618EA360z 0x61943318z 0x6194D918z 0x6194E0BCz Created !!!
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
//17/6CD13618A62E/SIP/Error/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Invalid CCB/Data/Container
//17/6CD13618A62E/SIP/Error/sipAddSipContainerToCallEntry: Unable to add passthru hdrs
to container
//17/6CD13618A62E/SIP/State/sipSPIChangeState: 0x7136D548 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
//16/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>
Date: Tue, 25 Jun 2013 13:24:42 GMT
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
//17/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
CANCEL sip:4996540908@80.251.131.27:5060 SIP/2.0
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
From: <4996540000>;tag=87F4E4-19DE
To: <4996540908>
Date: Tue, 25 Jun 2013 13:24:28 GMT
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
CSeq: 101 CANCEL
Max-Forwards: 70
Timestamp: 1372166703
Reason: Q.850;cause=47
Content-Length: 0
//-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
Calling Number=, Called Number=4996540000, Peer Info Type=DIALPEER_INFO_SPEECH
//-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
Match Rule=DP_MATCH_DEST; Called Number=4996540000
//-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=4996540000, Expanded String=4996540000, Calling Number=
Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
//-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Result=-1
//-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
No Outgoing Dial-peer Is Matched; Result=NO_MATCH(-1)
//-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
//-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
Result=NO_MATCH(-1)
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Calling Number=4996540908, Called Number=, Voice-Interface=0x0,
Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
Peer Info Type=DIALPEER_INFO_SPEECH
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_ANSWER; Calling Number=4996540908
//-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
//-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=4996540908T
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
//-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Result=-1
//-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_ORIGINATE; Calling Number=4996540908
//-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
//-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=4996540908T
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
//-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Result=-1
//-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985
//-1/xxxxxxxxxxxx/
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/1),process = AFW_application_process.
-Traceback= 0x60FCB374z 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61EB2ACCz 0x61EA3C1Cz 0x61EA471Cz 0x61B01054z 0x61B012C8z 0x61995184z 0x6176FEF8z 0x62A01774z 0x62A3898Cz 0x62A6FE90z DPM/dpAssociateIncomingPeerCore:
Result=NO_MATCH(-1) After All Match Rules Attempt
//-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
//-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit@6613
//-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROGRESS
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_codec_byte_transrating: peer codec is different, not a xrating scenario, return FALSE
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_codec_byte_transrating: peer codec is different, not a xrating scenario, return FALSE
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_codec_byte_transrating: peer codec is different, not a xrating scenario, return FALSE
//16/6CD13618A62E/SIP/Info/ccsip_query_force_association: REINVITE_NEEDED is FALSE. return FALSE
//17/6CD13618A62E/SIP/Info/ccsip_query_force_association: REINVITE_NEEDED is FALSE. return FALSE
//16/6CD13618A62E/SIP/Info/ccsip_bridge: confID = 8, srcCallID = 16, dstCallID = 17
//16/6CD13618A62E/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 16/17
//16/6CD13618A62E/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=-1, new streamcallid=16
//16/6CD13618A62E/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
//16/6CD13618A62E/SIP/Info/ccsip_bridge: xcoder_attached = 0, xmitFunc = 1674000596, ccb xmitFunc = 1674000596
//16/6CD13618A62E/SIP/Info/ccsip_spi_check_call_locally_held: CCSIP: call is locally noton-hold
//16/6CD13618A62E/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (cal
%SYS-3-CPUHOG: Task is running for (4004)msecs, more than (2000)msecs (1/1),process = AFW_application_process.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61A9DD94z 0x61A9F11Cz 0x619A354Cz 0x617CE700z 0x62A0E2C0z 0x62A2B5CCz 0x62A38A38z 0x62A6FE90z 0x62A36A4Cz 0x62A3DFACz lid 16) to the VOIP RTP library
//16/6CD13618A62E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
//16/6CD13618A62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
//16/6CD13618A62E/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
//16/6CD13618A62E/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 80.251.131.28, lport = 19374, raddr = 80.251.131.133, rport=17254, do_rtcp=TRUE
src_callid = 16, dest_callid = 17, stream type = voice+dtmf, stream direction = SENDRECV
media_ip_addr = 80.251.131.133, vrf tableid = 0 media_addr_type = 1
//16/6CD13618A62E/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
//16/6CD13618A62E/SIP/Info/sipSPICreateRtpSession: sess: 697E2230 do_rtcp:1
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: Populate gccb for nte rx is96 tx is 101
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for nse
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: Populate gccb for nte rx is101 tx is 96
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for nse
//16/6CD13618A62E/SIP/Media/sipSPICreateRtpSession: stun is disabled
//16/6CD13618A62E/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
//16/6CD13618A62E/SIP/Media/sipSPIGetNewLocalMediaDirection:
New Remot
%SYS-3-CPUHOG: Task is running for (6004)msecs, more than (2000)msecs (1/1),process = AFW_application_process.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61A8ED94z 0x61A9DA80z 0x61A9E2CCz 0x61A9F11Cz 0x619A354Cz 0x617CE700z 0x62A0E2C0z 0x62A2B5CCz 0x62A38A38z 0x62A6FE90z e Media Direction = SENDRECV
Present Local Media Direction = SENDRECV
New Local Media Direction = SENDRECV
retVal = 0
//16/6CD13618A62E/SIP/State/sipSPIChangeStreamState: Stream (callid = 16) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
//17/6CD13618A62E/SIP/Info/ccsip_bridge: confID = 8, srcCallID = 17, dstCallID = 16
//17/6CD13618A62E/SIP/Info/sipSPIUupdateCcCallIds: Old src/dest ccCallids: -1/-1, new src/dest ccCallids: 17/16
//17/6CD13618A62E/SIP/Info/sipSPIUupdateCcCallIds: Old streamcallid=17, new streamcallid=17
//17/6CD13618A62E/SIP/Info/ccsip_gw_set_sipspi_mode: Setting SPI mode to SIP-SIP
//17/6CD13618A62E/SIP/Info/ccsip_bridge: xcoder_attached = 0, xmitFunc = 1674000596, ccb xmitFunc = 1674000596
//17/6CD13618A62E/SIP/Info/ccsip_spi_check_call_locally_held: CCSIP: call is locally noton-hold
//17/6CD13618A62E/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 17) to the VOIP RTP library
//17/6CD13618A62E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
//17/6CD13618A62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
//17/6CD13618A62E/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
//17/6CD13618A62E/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 80.251.131.28, lport = 16584, raddr = 80.251.131.27, rport=10334, do_rtcp=TRUE
src_callid = 17, dest_callid = 16, stream type = voice+dtmf, stream direction = SENDRECV
media_ip_addr = 80.251.131.27, vrf tableid = 0 media_addr_type = 1
//17/6CD13618A62E/SIP/
%SYS-3-CPUHOG: Task is running for (8004)msecs, more than (2000)msecs (2/1),process = AFW_application_process.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61A9C09Cz 0x61A9E0ECz 0x61A9F11Cz 0x619A354Cz 0x617CE958z 0x62A0E2C0z 0x62A2B5CCz 0x62A38A38z 0x62A6FE90z 0x62A36A4Cz Media/sipSPIUpdateRtcpSession: RTP session already created - update
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: Populate gccb for nte rx is101 tx is 96
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for nse
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: Populate gccb for nte rx is96 tx is 101
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for nse
//17/6CD13618A62E/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:68C0E900
//17/6CD13618A62E/SIP/Info/sipSPICreateAndStartRtpTimer: Media Inactivity Timer is disabled.
//17/6CD13618A62E/SIP/Media/sipSPIGetNewLocalMediaDirection:
New Remote Media Direction = SENDRECV
Present Local Media Direction = SENDRECV
New Local Media Direction = SENDRECV
retVal = 0
//17/6CD13618A62E/SIP/State/sipSPIChangeStreamState: Stream (callid = 17) State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//17/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 183 Session Progress
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Content-Length: 225
Content-Type: application/sdp
CSeq: 101 INVITE
From: <4996540000>;tag=87F4E4-19DE
Require: 100rel
RSeq: 7000
To: <4996540908>;tag=50fb831b-96
User-Agent: Quintum/1.0.0 SN/0030E1103326
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
Quintum: 070e0000000c00000006001e03808081
v=0
o=Quintum 78 722 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10334 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
a=sendrecv
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//17/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 183 Session Progress
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Content-Length: 225
Content-Type: application/sdp
CSeq: 101 INVITE
From: <4996540000>;tag=87F4E4-19DE
Require: 100rel
RSeq: 7000
To: <4996540908>;tag=50fb831b-96
User-Agent: Quintum/1.0.0 SN/0030E1103326
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
Quintum: 070e0000000c00000006001e03808081
v=0
o=Quintum 78 722 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10334 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
a=sendrecv
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: Populate gccb for nte rx is96 tx is 101
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for nse
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: Populate gccb for nte rx is101 tx is 96
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for nse
//16/6CD13618A62E/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:70F0BAA4
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: Populate gccb for nte rx is101 tx is 96
//16/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for nse
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for stream type 1
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: Populate gccb for nte rx is96 tx is 101
//17/6CD13618A62E/SIP/Info/updateGccbTxRxValues: No interworking required for nse
//17/6CD13618A62E/SIP/Media/sipSPIUpdateRtpSession: stun is disabled for stream:68C0E900
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 27
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callID 16 ft: 1, inc 4, 80.251.131.27:10334, codec 6
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_handle_channel_info:
CCSIP:callid 16 state STATE_RECD_INVITE
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_handle_channel_info: Reset FAX_PASSTHROUGH
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_handle_channel_info: Reset IS_FAX_TO_VOICE_SWITCH..
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
callid 16, channels 0x68C1D1DC caps 0x7125D4D8
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: Peer cap provided: callid = 16, peer dtmf = 6peer t38 version = 0 peer t38 maxBitRate = 9600
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_vcc_ResponseFilterCodecs: codec copied to reference_codec_list = 6
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_vcc_ResponseFilterCodecs: codec copied to reference_codec_list = 5
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_vcc_ResponseFilterCodecs: codec copied to reference_codec_list = 16
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_vcc_ResponseFilterCodecs: codec copied to reference_codec_list = 14
//16/6CD13618A62E/SIP/Info/codec_found:
Codec to be matched: 6
//16/6CD13618A62E/SIP/Info/sipSPIUpdatePreferredCodec: num_chans = 1
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_vcc_ResponseFilterCodecs: Static-codec/Equalset/ Subset(with common codec) case..
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp:
nego mline 1 dtmf 101 ss 1 ret 12
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: Reset IS_FAX_TO_VOICE_SWITCH
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: CCB->pld.flags_ipip 0x400443
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_channelInfo_to_sdp: channel_ind/ack payload type 8
//-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Cod
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61AA445Cz 0x619F8130z 0x619FBD10z 0x61A8A4CCz 0x619453C0z 0x6194E0CCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z ec: g711alaw codecbytes :160, ptime: 20
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_handle_channel_info: audio channel_ind
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
//16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 19374
//16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 6, payload type 8
//16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 96
//16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 15
//16/6CD13618A62E/SIP/Info/sipSPIProcessMediaChanges: sipSPIProcessMediaChanges
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
//16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 19374
//16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 6, payload type 8
//16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 96
//16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 15
//17/6CD13618A62E/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
//-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 4
//16/6CD13618A62E/SIP/Info/sipSPIAddCiscoGcid: Fatal Error in parsing CCB/Msg
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIStoreTunnelData: Container /RawMessage Absent
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container
//16/6CD13618A62E/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
//16/6CD13618A62E/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x7137DCA0 key=6ce116f0dda211e2a907001a64c74ed8@80.251.131.13288D424-D7F
//16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
//16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:183, container:710FD96C
//16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing
//16/6CD13618A62E/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 10 event
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//16/6CD13618A62E/SIP/Info/sipSPIPushSubsqTransMsgContainerIntoHolder: Response Container Holder is above threshold...trimming
//16/6CD13618A62E/SIP/Info/ccsip_api_update_allowed: UPDATE(1) allowed
//16/6CD13618A62E/SIP/Info/ccsip_offer_ans_handle_update_allowed:
//16/6CD13618A62E/SIP/Event/sipSPICreateRpid: Received Octet3A=0x81 -> Setting ;screen=yes ;privacy=off
SIP: (16) Group (a= group line) attribute, level 65535 instance 1 not found.
//16/6CD13618A62E/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp and dest_sdp available, should be a midcall request
//16/6CD13618A62E/SIP/Info/sipSPISendInviteResponse: Associated contai
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (0/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61921DF8z 0x619221C4z 0x61936C78z 0x619453C0z 0x6194E0CCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z ner=0x710FD96C to Invite Response 183
//16/6CD13618A62E/SIP/Transport/sipSPISendInviteResponse: Sending 183 Response to the Transport Layer
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x715DD644, addr=80.251.131.132, port=5061, sentBy_port=5061, local_addr=, is_req=0, transport=1, switch=0, callBack=0x61B5E4B8
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x715DD644 to default port=5061
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.132, rport:5061 with laddr:
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x715DD644
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x715DD644, addr=80.251.131.132, port=5061, local_addr=, connId=2 for UDP
//16/6CD13618A62E/SIP/Info/sentInviteResponse18x: Sent a 18x Response
//16/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>;tag=88D424-D7F
Date: Tue, 25 Jun 2013 13:24:42 GMT
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: <4996540908>;party=called;screen=yes;privacy=off
Contact: <0008014996540908>
Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 247
v=0
o=CiscoSystemsSIP-GW-UserAgent 4926 2076 IN IP4 80.251.131.28
s=SIP Call
c=IN IP4 80.251.131.28
t=0 0
m=audio 19374 RTP/AVP 8 96
c=IN IP4 80.251.131.28
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=ptime:20
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//17/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 183 Session Progress
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Content-Length: 225
Content-Type: application/sdp
CSeq: 101 INVITE
From: <4996540000>;tag=87F4E4-19DE
Require: 100rel
RSeq: 7000
To: <4996540908>;tag=50fb831b-96
User-Agent: Quintum/1.0.0 SN/0030E1103326
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
Quintum: 070e0000000c00000006001e03808081
v=0
o=Quintum 78 722 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10334 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
a=sendrecv
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//17/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 183 Session Progress
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Content-Length: 225
Content-Type: application/sdp
CSeq: 101 INVITE
From: <4996540000>;tag=87F4E4-19DE
Require: 100rel
RSeq: 7000
To: <4996540908>;tag=50fb831b-96
User-Agent: Quintum/1.0.0 SN/0030E1103326
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
Quintum: 070e0000000c00000006001e03808081
v=0
o=Quintum 78 722 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10334 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
a=sendrecv
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//17/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 183 Session Progress
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Content-Length: 225
Content-Type: application/sdp
CSeq: 101 INVITE
From: <4996540000>;tag=87F4E4-19DE
Require: 100rel
RSeq: 7000
To: <4996540908>;tag=50fb831b-96
User-Agent: Quintum/1.0.0 SN/0030E1103326
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
Quintum: 070e0000000c00000006001e03808081
v=0
o=Quintum 78 722 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10334 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
a=sendrecv
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.132]:5061, local_address:[ - ]
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
//17/6CD13618A62E/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XXINVITE sip:0008014996540908@80.251.131.28;user=phone SIP/2.0
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Contact: <4996540000>
Content-Type: application/sdp
Allow: ACK, BYE, CANCEL, INFO,
//17/6CD13618A62E/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 1 event INVITE, OPTIONS, REFER, REGISTER, UPDATE
Max-Forwards: 70
User-Agent: MERA MVTS3G v.4.4.0-15
Cisco-Guid: 1825650200-3718386146-2788032538-1690784136
Remote-Party-ID: <4996540000>;party=calling;privacy=off;screen=yes
Content-Length: 319
v=0
o=- 1372170045 1372170045 IN IP4 80.251.131.133
s=-
c=IN IP4 80.251.131.133
t=0 0
m=audio 17254 RTP/AVP 8 0 18 4 96
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=fmtp:4 annexa=yes
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x7137DCA0) with key=[157] to table
*Jun 25 13:24:28.191: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry...
*Jun 25 13:24:28.191: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.132,Port 5061, Transport 1, SentBy Port 5061
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 80.251.131.28
*Jun 25 13:24:28.191: //-1/6CD13618A62E/SIP/State/sipSPIChangeState: 0x7137DCA0 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.132,Port 5061, Transport 1, SentBy Port 5060
*Jun 25 13:24:28.191: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
%SYS-3-CPUHOG: Task is running for (2696)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB374z 0x60381D1Cz 0x60381CD4z 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61A15528z 0x61A15D10z 0x61B15304z 0x619194F8z 0x61941AB8z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z
//17/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.132,Port 5061, Transport 1, SentBy Port 5061
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 80.251.131.28
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
Calling Number=0008014996540908, Called Number=0008014996540908, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
Match Rule=DP_MATCH_DEST; Called Number=0008014996540908
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=0008014996540908, Expanded String=0008014996540908, Calling Number=0008014996540908T
Timeout=TRUE, Is Incoming=FALSE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/MatchNextPeer:
Result=Success(0); Outgoing Dial-peer=801 Is Matched
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
Result=Success(0) after DP_MATCH_DEST
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
%SYS-3-CPUHOG: Task is running for (4540)msecs, more than (2000)msecs (2/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB374z 0x60381D1Cz 0x60381CD4z 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61971BF8z 0x61915AD0z 0x6191950Cz 0x61941AB8z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z
//17/6CD13618A62E/SIP/Info/sipSPIPushOrigRequestContainerIntoHolder: Request Container Holder is above threshold...trimmingdialstring=0008014996540908, saf_enabled=1, saf_dndb_lookup=1, dp_result=0
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
Result=SUCCESS(0)
List of Matched Outgoing Dial-peer(s):
1: Dial-peer Tag=801
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x680949DC) found for sip_user: 0008014996540908
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: , current remote number: 4996540000
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
%SYS-3-CPUHOG: Task is running for (6320)msecs, more than (2000)msecs (2/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB374z 0x60381D1Cz 0x60381CD4z 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61919AD8z 0x61941AB8z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z
//17/6CD13618A62E/SIP/Info/sipSPISendAck: Associated container=0x710FD654 to Ack
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x7137DCA0 key=6ce116f0dda211e2a907001a64c74ed8@80.251.131.1320008014996540908
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Calling Number=4996540000, Called Number=, Voice-Interface=0x0,
Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_ANSWER; Calling Number=4996540000
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
%SYS-3-CPUHOG: Task is running for (8032)msecs, more than (2000)msecs (2/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61919C1Cz 0x61941AB8z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z //17/6CD13618A62E/SIP/Transport/sipSPISendAck: Sending ACK to the transport layer
//17/6CD13618A62E/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE
//17/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x70669DE8, addr=80.251.131.27, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x0
//17/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//17/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.27, rport:5060 with laddr:
//17/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x70669DE8
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x70669DE8, addr=80.251.131.27, port=5060, local_addr=, connId=3 for UDP
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
ACK sip:4996540908@80.251.131.27:5060 SIP/2.0
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
From: <4996540000>;tag=87F4E4-19DE
To: <4996540908>;tag=50fb831b-96
Date: Tue, 25 Jun 2013 13:24:28 GMT
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
ACK sip:4996540908@80.251.131.27:5060 SIP/2.0
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK71B11
From: <4996540000>;tag=87F4E4-19DE
To: <4996540908>;tag=50fb831b-96
Date: Tue, 25 Jun 2013 13:24:28 GMT
Call-ID: 656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0
//16/6CD13618A62E/SIP/Info/ccsip_call_statistics: Stats are not supported for IPIP call.
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
//-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_DISCONNECT
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
//-1/xxxxxxxxxxxx/SIP/Error/ccsip_spi_process_ccapi_event: CCB not found for application event 8 withcallID: 17
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 8
//16/6CD13618A62E/SIP/Info/act_recdinvite_disconnect: Performing disconnect
//16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
//16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:503, container:710FD12C
//16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_RESP
//16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:80, posted event:E_STSL_INVALID_PEER_EVENT, reason:3
Configured SE:1800, Configured Min-SE:1800
//16/6CD13618A62E/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 3 event
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
//16/6CD13618A62E/SIP/Info/sipSPIPushSubsqTransMsgContainerIntoHolder: Response Container Holder is above threshold...trimming
//16/6CD13618A62E/SIP/Info/sipSPISendInviteResponse: Associated container=0x710FD12C to Invite Response 503
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x68C15B8C, addr=80.251.131.132, port=5061, sentBy_port=5061, local_addr=, is_req=0, transport=1, switch=0, callBack=0x61B5DD60
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x68C15B8C to default port=5061
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.132, rport:5061 with laddr:
//16/6CD13618A62E/SIP/Transport/sipTra
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/0),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16DB4z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61B65588z 0x61B66210z 0x619220D8z 0x61937620z 0x619453C0z 0x6194E0CCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z nsportLogicSendMsg: Connection obtained...sending msg=0x68C15B8C
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x68C15B8C, addr=80.251.131.132, port=5061, local_addr=, connId=2 for UDP
//16/6CD13618A62E/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response
//16/6CD13618A62E/SIP/State/sipSPIChangeState: 0x7137DCA0 : State change from (STATE_RECD_INVITE, SUBSTATE_NONE) to (STATE_DISCONNECTING, SUBSTATE_NONE)
//16/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>;tag=88D424-D7F
Date: Tue, 25 Jun 2013 13:24:42 GMT
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=47
Content-Length: 0
//16/6CD13618A62E/SIP/Info/sipSPISendInviteResponse: Associated container=0x710FD12C to Invite Response 503
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x68C0F720, addr=80.251.131.132, port=5061, sentBy_port=5061, local_addr=, is_req=0, transport=1, switch=0, callBack=0x0
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x68C0F720 to default port=5061
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.132, rport:5061 with laddr:
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x68C0F720
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x68C0F720, addr=80.251.131.132, port=5061, local_addr=, connId=2 for UDP
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.132]:5061, local_address:[ - ]
//16/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>;tag=88D424-D7F
Date: Tue, 25 Jun 2013 13:24:42 GMT
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=47
Content-Length: 0
//16/6CD13618A62E/SIP/Info/sipSPISendInviteResponse: Associated container=0x710FD12C to Invite Response 503
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x68C15B8C, addr=80.251.131.132, port=5061, sentBy_port=5061, local_addr=, is_req=0, transport=1, switch=0, callBack=0x0
//16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x68C15B8C to default port=5061
//-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.132, rport:5061 with laddr:
//16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x68C15B8C
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x68C15B8C, addr=80.251.131.132, port=5061, local_addr=, connId=2 for UDP
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.132]:5061, local_address:[ - ]
//16/6CD13618A62E/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>;tag=88D424-D7F
Date: Tue, 25 Jun 2013 13:24:42 GMT
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=47
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:0008014996540908@80.251.131.28;user=phone SIP/2.0
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>;tag=88D424-D7F
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 ACK
Max-Forwards: 70
User-Agent: MERA MVTS3G v.4.4.0-15
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//16/6CD13618A62E/SIP/Info/sipSPIFindCcbUASRespTable: *****CCB found in UAS Response table. ccb=0x7137DCA0
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 80.251.131.132,Port 5061, Transport 1, SentBy Port 5060
//-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
//-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 80.251.131.132,Port 5061, Transport 1, SentBy Port 5061
//16/6CD13618A62E/SIP/Info/sipSPIIcpifUpdate: CallState: 2 Playout: 0 DiscTime:899392 ConnTime 0
//16/6CD13618A62E/SIP/Media/sipSPIDestroyRtpSession: stream:70F0BAA4
//16/6CD13618A62E/SIP/State/sipSPIChangeState: 0x7137DCA0 : State change from (STATE_DISCONNECTING, SUBSTATE_NONE) to (STATE_DEAD, SUBSTATE_NONE)
//16/6CD13618A62E/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x7137DCA0
State of The Call : STATE_DEAD
TCP Sockets Used : NO
Calling Number : 4996540000
Called Number : 0008014996540908
Source IP Address (Sig ): 80.251.131.28
D
%SYS-3-CPUHOG: Task is running for (2004)msecs, more than (2000)msecs (1/1),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61979D94z 0x6197A130z 0x619331B4z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z estn SIP Req Addr:Port : 80.251.131.132:5061
Destn SIP Resp Addr:Port : 80.251.131.132:5061
Destination Name : 80.251.131.132
//16/6CD13618A62E/SIP/Call/sipSPIMediaCallInfo:
Number of Media Streams: 1
Media Stream : 1
Negotiated Codec : g711alaw
Negotiated Codec Bytes : 160
Nego. Codec payload : 8 (tx), 8 (rx)
Negotiated Dtmf-relay : 6
Dtmf-relay Payload : 96 (tx), 96 (rx)
Source IP Address (Media): 80.251.131.28
Source IP Port (Media): 19374
Destn IP Address (Media): 80.251.131.133
Destn IP Port (Media): 17254
Orig Destn IP Address:Port (Media): [ - ]:0
//16/6CD13618A62E/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 47
Disconnect Cause (SIP) : 503
//16/6CD13618A62E/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 10
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[157] removed.
//16/6CD13618A62E/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
//16/6CD13618A62E/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x7137DCA0 key=6ce116f0dda211e2a907001a64c74ed8@80.251.131.1320008014996540908
//16/6CD13618A62E/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
//16/6CD13618A62E/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x7137DCA0 key=6ce116f0dda211e2a907001a64c74ed8@80.251.131.13288D424-D7F
//16/6CD13618A62E/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
//16/6CD13618A62E/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Prof
%SYS-3-CPUHOG: Task is running for (4004)msecs, more than (2000)msecs (1/1),process = CCSIP_SPI_CONTROL.
-Traceback= 0x60FCB36Cz 0x60381D1Cz 0x61D16F70z 0x61D153F0z 0x61DE6D5Cz 0x61DE6E4Cz 0x61B21A7Cz 0x61976DC4z 0x619331B4z 0x6194D918z 0x6194E0BCz 0x61AE3D68z 0x61AE4230z 0x63A2F6B0z 0x63A2F694z iles Freed
//16/6CD13618A62E/SIP/Info/ccsip_offer_ans_delete:
//16/6CD13618A62E/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 7137DCA0
//-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[157]
//-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.132]:5061, local_address:[ - ]
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:0008014996540908@80.251.131.28;user=phone SIP/2.0
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>;tag=88D424-D7F
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 ACK
Max-Forwards: 70
User-Agent: MERA MVTS3G v.4.4.0-15
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//-1/xxxxxxxxxxxx/SIP/Error/sipSPISipIncomingMsg: Invalid method for (STATE_IDLE): ACK
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
//-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
//-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:0008014996540908@80.251.131.28;user=phone SIP/2.0
Via: SIP/2.0/UDP 80.251.131.132:5061;rport;branch=z9hG4bK-2487935340-3792806621-436209577-3629041508
From: <4996540000>;tag=3524714860-3792806621-436209577-3629041508
To: <0008014996540908>;tag=88D424-D7F
Call-ID: 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
CSeq: 1 ACK
Max-Forwards: 70
User-Agent: MERA MVTS3G v.4.4.0-15
Content-Length: 0
//-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
//-1/xxxxxxxxxxxx/SIP/Error/sipSPISipIncomingMsg: Invalid method for (STATE_IDLE): ACK
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=4996540000T
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Result=-1
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_ORIGINATE; Calling Number=4996540000
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=4996540000T
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Result=-1
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Resu
Router#lt=NO_MATCH(-1) After All Match Rules Attempt
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit@6613
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 0008014996540908
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 4996540000
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name , number 4996540000, Calling oct3 0x00, oct_3a 0x81, Called number 0008014996540908
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:80.251.131.132:5061, Host:80.251.131.132
*Jun 25 13:24:28.195: //-1/6CD13618A62E/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 4996540000
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Calling Number=4996540000, Called Number=, Voice-Interface=0x0,
Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_ANSWER; Calling Number=4996540000
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=4996540000T
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Result=-1
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_ORIGINATE; Calling Number=4996540000
*Jun 25 13:24:28.195: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=4996540000T
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/DPM/dpMatchCore:
Result=-1
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/DPM/dpMatchPeertype:exit@5985
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
Result=NO_MATCH(-1) After All Match Rules Attempt
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeer:exit@6613
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpAssociateIncomingPeerCore:
Calling Number=4996540000, Called Number=0008014996540908, Voice-Interface=0x0,
Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_VIA_URI; URI=sip:80.251.131.132:5061
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchCore:
Result=-1
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchPeertype:exit@5985
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_REQUEST_URI; URI=sip:0008014996540908@80.251.131.28;user=phone
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchCore:
Result=-1
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchPeertype:exit@5985
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_TO_URI; URI=sip:0008014996540908@80.251.131.28;user=phone
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchCore:
Result=-1
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchPeertype:exit@5985
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpAssociateIncomingPeerCore:
Match Rule=DP_MATCH_FROM_URI; URI=sip:4996540000@80.251.131.132:5061;user=phone
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchPeertype:
Is Incoming=TRUE, Number Expansion=FALSE
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchCore:
Dial String=, Expanded String=, Calling Number=
Timeout=TRUE, Is Incoming=TRUE, Peer Info Type=DIALPEER_INFO_SPEECH
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/MatchNextPeer:
Result=Success(0); Incoming Dial-peer=901 Is Matched
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchPeertype:exit@5985
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpAssociateIncomingPeerCore:
Result=Success(0) after DP_MATCH_FROM_URI; Incoming Dial-peer=901
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpMatchSafModulePlugin:
dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
*Jun 25 13:24:28.199: //-1/6CD13618A62E/DPM/dpAssociateIncomingPeerSPI:exit@6564
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetCallConfig: Peer tag 901 matched for incoming call
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 80.251.131.28
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetModemConfig:
From Config: Modem NSE payload = 100, Passthrough = 4, Modem relay = 0, Gw-Xid = 1
SPRT latency 200, SPRT Retries = 12, Dict Size = 1024
String Len = 32, Compress dir = 3
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIGetCallConfig: Media forking disabled
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIContinueNewMsgInvite: Calling name , number 4996540000, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 0008014996540908, oct3 0x00
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIValidateRequestUri: Not Enabled
*Jun 25 13:24:28.199: //-1/6CD13618A62E/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled: - 0
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:710FD3EC
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Not received session expires header
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_LEG_BY_LEG, SE Value:0, SE Refresher:none, Min-SE Value:1800, flags:2000
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 17254
SIP: (16) Attribute mid, level 1 instance 1 not found.
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 80.251.131.28
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(96) could not be reserved
as its in use by other codec No Codec
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (96) is reserved by another application
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 96 for Codec:
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0
*Jun 25 13:24:28.199: //16/6CD13618A62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(96) reserved for codec
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(96) could not be reserved
as its in use by other codec
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (96) is reserved by another application
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101
*Jun 25 13:24:28.199: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 96 for RTP-NTE
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events.
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=rtp-nte
stream_type=voice+dtmf (1), dest_ip_address=80.251.131.133, dest_port=17254
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Media/sipSPIUpdCallWithSdpInfo:
Preferred Codec : transparent, bytes
Preferred DTMF relay : rtp-nte
Preferred NTE payload : 96
Early Media : No
Delayed Media : No
Bridge Done : No
New Media : No
DSP DNLD Reqd : No
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 16 peer 0 flags 0x241 state STATE_IDLE
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_vcc_ProcessXcoderNeeded: xcoder_attached not yet initialised for this call.
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Xcoder not yet used for the call
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 16, Peer CallID 0, sdp 0x69368D88 channels 0x7137F23C
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/copy_channels:
callId 16 size 0 ptr 0x69C52DF0)
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB t38 version 0 ipip_caps version 0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB fax rate 32 ipip_caps rate 9600
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: reset the switch..
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 8 mline 1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/codec_found:
Codec to be matched: 6
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=0,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 6 ptype 8 time 20, bytes 160 as channel 0 mline 1 ss 1 80.251.131.133:17254
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/codec_found:
Codec to be matched: 5
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5
SIP: (16) Attribute ptime, level 1 instance 1 not found.
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=0, media_ndx=1
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :0, codecbytes: 0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Codec bytes 0, use default packet rate 160
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 5 ptype 0 time 0, bytes 160 as channel 1 mline 1 ss 1 80.251.131.133:17254
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 18 mline 1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729r8
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/codec_found:
Codec to be matched: 16
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 16
SIP: (16) Attribute ptime, level 1 instance 1 not found.
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=0, media_ndx=1
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729r8 ptime :0, codecbytes: 0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Codec bytes 0, use default packet rate 20
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 16 ptype 18 time 0, bytes 20 as channel 2 mline 1 ss 1 80.251.131.133:17254
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 4 mline 1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g723ar63
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/codec_found:
Codec to be matched: 14
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 14
SIP: (16) Attribute ptime, level 1 instance 1 not found.
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=0, media_ndx=1
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g723ar63 ptime :0, codecbytes: 0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Codec bytes 0, use default packet rate 24
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 14 ptype 4 time 0, bytes 24 as channel 3 mline 1 ss 1 80.251.131.133:17254
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 96 mline 1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 16, dtmf = 6
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 6
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 16
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 14
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 16 flags 0x10000100 state STATE_IDLE
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC, ccb->pld.flags_ipip 0x241
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/copy_channels:
callId 16 size 924 ptr 0x6A566944)
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
CCSIP: Unable to report channel ind
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/ccsip_update_srtp_caps: 7415: Posting Remote SRTP caps to other callleg.
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Updating the negotiated codec bytes
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_report_media_to_peer: do cc_api_caps_ind()
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Media/sipSPIUpdCallWithSdpInfo:
Stream type : voice+dtmf
Media line : 1
State : STREAM_ADDING (2)
Stream address type : 1
Callid : -1
Negotiated Codec : g711alaw, bytes :160
Nego. Codec payload : 8 (tx), 8 (rx)
Negotiated DTMF relay : rtp-nte
Negotiated NTE payload : 96 (tx), 96 (rx)
Negotiated CN payload : 0
Media Srce Addr/Port : [80.251.131.28]:0
Media Dest Addr/Port : [80.251.131.133]:17254
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIHandleInviteMedia:
Negotiated Codec : g711alaw, bytes :160
Preferred Codec : transparent, bytes
Preferred DTMF relay 1 : 6
Preferred DTMF relay 2 : 0
Negotiated DTMF relay : 6
Preferred and Negotiated NTE payloads: 96 96
Preferred and Negotiated NSE payloads: 100 0
Preferred and Negotiated Modem Relay: 0 0
Preferred and Negotiated V150.1 Modem Passthrough: 0 0
Preferred and Negotiated V150.1 Modem Relay: 0 0
Preferred and Negotiated Modem Relay GwXid: 1 0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 19374 for stream 1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=19374
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 19374
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 6, payload type 8
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 96
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 16
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 6ce116f0dda211e2a907001a64c74ed8@80.251.131.132
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Error/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 0
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Error/ccsip_api_call_setup_ind: Unable to add unsupp headers to container
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/ccsip_api_call_setup_ind: Set Protocol information
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 6,
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/sipSPIShrlCall: Check peer: 901 for Shared-Line call, callid: 16
*Jun 25 13:24:28.203: //16/6CD13618A62E/SIP/Info/ccsip_set_bearer_capability:
Bearer Capability: Speech (0x00)
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Jun 25 13:24:28.203: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 10 to table
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, container:710FCC04
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Info/sipSPISendInviteResponse: Associated container=0x710FCC04 to Invite Response 100
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: msg=0x6A02BD10, addr=80.251.131.132, port=5061, sentBy_port=5061, local_addr=, is_req=0, transport=1, switch=0, callBack=0x0
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Jun 25 13:24:28.207: //16/6CD13618A62E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x6A02BD10 to default port=5061
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x68C19338,addr=80.251.131.132
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnHolder: Created new holder=0x68C19338, addr=80.251.131.132; nailed=FALSE
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for addr=80.251.131.132, port=5061, context=0x70771354
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for connection=0x70772C64,addr=80.251.131.132, port=5061
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer:
Wait Conn Timer started for 5000 msec
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new initiated conn=0x70772C64, connid=-1, addr=80.251.131.132, port=5061, local_addr=, transport=UDP
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.132, rport:5061 with laddr:
*Jun 25 13:24:28.207: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x7137DCA0 with connection=0x70772C64
*Jun 25 13:26:04.847: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[158] removed.
*Jun 25 13:26:04.847: //17/6CD13618A62E/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
*Jun 25 13:26:04.847: //17/6CD13618A62E/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x7136D548 key=656906EA-DCD111E2-80C293BC-5853A7A8@80.251.131.28
*Jun 25 13:26:04.847: //17/6CD13618A62E/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Jun 25 13:26:04.847: //17/6CD13618A62E/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
*Jun 25 13:26:04.847: //17/6CD13618A62E/SIP/Info/ccsip_offer_ans_delete:
*Jun 25 13:26:04.847: //17/6CD13618A62E/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 7136D548
Router#
Router#
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-25-2013 08:11 AM
It looks like you may have some UDP traffic loss. Many of those SIP messages are resent. Also, make sure PRACK is enabled in CUCM.
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-25-2013 08:30 AM
UDP is all right! debug ccsip impacts on CPU strongly. I don't know how to avoid this.
What is PRACK?
Whan is CUCM?
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-25-2013 08:32 AM
Try this:
*Jun 25 14:34:40.383: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.133]:5061, local_address:[ - ]
*Jun 25 14:34:40.383: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Jun 25 14:34:40.383: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
*Jun 25 14:34:40.383: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:0008014996540908@80.251.131.28;user=phone SIP/2.0
Via: SIP/2.0/UDP 80.251.131.133:5061;rport;branch=z9hG4bK-110469435-3792809181-436258723-408012644
From: <4996540000>;tag=1046978875-3792809181-436258723-408012644
To: <0008014996540908>
Call-ID: 3ba1675cddac11e2a3c7001a64c75118@80.251.131.133
CSeq: 1 INVITE
Contact: <4996540000>
Content-Type: application/sdp
Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, REFER, REGISTER, UPDATE
Max-Forwards: 70
User-Agent: MERA MVTS3G v.4.4.0-15
Cisco-Guid: 997459390-3719041506-2788032538-1690784136
Remote-Party-ID: <4996540000>;party=calling;privacy=off;screen=yes
Content-Length: 319
v=0
o=- 1372174257 1372174257 IN IP4 80.251.131.133
s=-
c=IN IP4 80.251.131.133
t=0 0
m=audio 19774 RTP/AVP 8 0 18 4 96
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=fmtp:4 annexa=yes
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=sendrecv
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x713784D8) with key=[165] to table
*Jun 25 14:34:40.387: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry...
*Jun 25 14:34:40.387: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.133,Port 5061, Transport 1, SentBy Port 5061
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 80.251.131.28
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/State/sipSPIChangeState: 0x713784D8 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.133,Port 5061, Transport 1, SentBy Port 5060
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Clock Time Zone is UTC, same as GMT: Using GMT
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 80.251.131.133,Port 5061, Transport 1, SentBy Port 5061
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 80.251.131.28
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckIpip: VOIP dialpeer (peer=0x680949DC) found for sip_user: 0008014996540908
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPISetInfoFromRpid: Received current remote name: , current remote number: 4996540000
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPISetInfoFromRpid: Received ;screen=yes ;privacy=off -> Setting Octet3A 0x81, extended_privacy 0x00
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Jun 25 14:34:40.387: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x713784D8 key=3ba1675cddac11e2a3c7001a64c75118@80.251.131.1330008014996540908
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 0008014996540908
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 4996540000
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name , number 4996540000, Calling oct3 0x00, oct_3a 0x81, Called number 0008014996540908
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:80.251.131.133:5061, Host:80.251.131.133
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 4996540000
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
*Jun 25 14:34:40.387: //-1/3B7405BEA62E/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetCallConfig: Peer tag 901 matched for incoming call
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 80.251.131.28
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetCallConfig: Checking Video Type Rate=-1 video_codec_allowed=1F
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetModemConfig:
From Config: Modem NSE payload = 100, Passthrough = 4, Modem relay = 0, Gw-Xid = 1
SPRT latency 200, SPRT Retries = 12, Dict Size = 1024
String Len = 32, Compress dir = 3
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIGetCallConfig: Media forking disabled
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIContinueNewMsgInvite: Calling name , number 4996540000, Calling oct3 0x00, oct_3a 0x81, ext_priv 0x00, Called number 0008014996540908, oct3 0x00
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIValidateRequestUri: Not Enabled
*Jun 25 14:34:40.391: //-1/3B7405BEA62E/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled: - 0
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:710FD5FC
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Not received session expires header
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_LEG_BY_LEG, SE Value:0, SE Refresher:none, Min-SE Value:1800, flags:2000
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:2000, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 19774
SIP: (24) Attribute mid, level 1 instance 1 not found.
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 80.251.131.28
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(96) could not be reserved
as its in use by other codec No Codec
Router#*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (96) is reserved by another application
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 96 for Codec:
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIDoPtimeNegotiation: No ptime present or multiple ptime attributes that can't be handled
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(96) reserved for codec
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(96) could not be reserved
as its in use by other codec
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (96) is reserved by another application
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 96 for RTP-NTE
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events.
*Jun 25 14:34:40.391: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=rtp-nte
stream_type=voice+dtmf (1), dest_ip_address=80.251.131.133, dest_port=19774
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Media/sipSPIUpdCallWithSdpInfo:
Preferred Codec : transparent, bytes
Preferred DTMF relay : rtp-nte
Preferred NTE payload : 96
Early Media : No
Delayed Media : No
Bridge Done : No
New Media : No
DSP DNLD Reqd : No
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 24 peer 0 flags 0x241 state STATE_IDLE
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_vcc_ProcessXcoderNeeded: xcoder_attached not yet initialised for this call.
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Xcoder not yet used for the call
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 24, Peer CallID 0, sdp 0x68C5F6EC channels 0x71379A74
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/copy_channels:
callId 24 size 0 ptr 0x70779574)
*Jun 25 14:34:40.391: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB t38 version 0 ipip_caps version 0
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB fax rate 32 ipip_caps rate 9600
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: reset the switch..
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 8 mline 1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/codec_found:
Codec to be matched: 6
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=0,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 6 ptype 8 time 20, bytes 160 as channel 0 mline 1 ss 1 80.251.131.133:19774
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711ulaw
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/codec_found:
Codec to be matched: 5
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 5
SIP: (24) Attribute ptime, level 1 instance 1 not found.
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=0, media_ndx=1
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711ulaw ptime :0, codecbytes: 0
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Codec bytes 0, use default packet rate 160
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 5 ptype 0 time 0, bytes 160 as channel 1 mline 1 ss 1 80.251.131.133:19774
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 18 mline 1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g729r8
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/codec_found:
Codec to be matched: 16
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 16
SIP: (24) Attribute ptime, level 1 instance 1 not found.
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=0, media_ndx=1
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g729r8 ptime :0, codecbytes: 0
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Codec bytes 0, use default packet rate 20
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 16 ptype 18 time 0, bytes 20 as channel 2 mline 1 ss 1 80.251.131.133:19774
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 4 mline 1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g723ar63
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/codec_found:
Codec to be matched: 14
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 14
SIP: (24) Attribute ptime, level 1 instance 1 not found.
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation NOT done, get ptime from sdp: ptime=0, media_ndx=1
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g723ar63 ptime :0, codecbytes: 0
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Codec bytes 0, use default packet rate 24
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
failed to update call entry
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 14 ptype 4 time 0, bytes 24 as channel 3 mline 1 ss 1 80.251.131.133:19774
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 96 mline 1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 24, dtmf = 6
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 6
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 5
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 16
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 14
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 24 flags 0x10000100 state STATE_IDLE
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0xC, ccb->pld.flags_ipip 0x241
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/copy_channels:
callId 24 size 924 ptr 0x68C18D30)
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
CCSIP: Unable to report channel ind
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/ccsip_update_srtp_caps: 7415: Posting Remote SRTP caps to other callleg.
*Jun 25 14:34
Router#:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Updating the negotiated codec bytes
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: do cc_api_caps_ind()
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Media/sipSPIUpdCallWithSdpInfo:
Stream type : voice+dtmf
Media line : 1
State : STREAM_ADDING (2)
Stream address type : 1
Callid : -1
Negotiated Codec : g711alaw, bytes :160
Nego. Codec payload : 8 (tx), 8 (rx)
Negotiated DTMF relay : rtp-nte
Negotiated NTE payload : 96 (tx), 96 (rx)
Negotiated CN payload : 0
Media Srce Addr/Port : [80.251.131.28]:0
Media Dest Addr/Port : [80.251.131.133]:19774
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIHandleInviteMedia:
Negotiated Codec : g711alaw, bytes :160
Preferred Codec : transparent, bytes
Preferred DTMF relay 1 : 6
Preferred DTMF relay 2 : 0
Negotiated DTMF relay : 6
Preferred and Negotiated NTE payloads: 96 96
Preferred and Negotiated NSE payloads: 100 0
Preferred and Negotiated Modem Relay: 0 0
Preferred and Negotiated V150.1 Modem Passthrough: 0 0
Preferred and Negotiated V150.1 Modem Relay: 0 0
Preferred and Negotiated Modem Relay GwXid: 1 0
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16454 for stream 1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16454
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16454
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
SIP update src sdp, negoitated codec 6, payload type 8
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 96
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 16
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 3ba1675cddac11e2a3c7001a64c75118@80.251.131.133
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Error/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 0
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Error/ccsip_api_call_setup_ind: Unable to add unsupp headers to container
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/ccsip_api_call_setup_ind: Set Protocol information
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 6,
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIShrlCall: Check peer: 901 for Shared-Line call, callid: 24
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/ccsip_set_bearer_capability:
Bearer Capability: Speech (0x00)
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Jun 25 14:34:40.395: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_SUCCESS
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 18 to table
*Jun 25 14:34:40.395: //24/3B7405BEA62E/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:100, container:710FD444
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Info/Session-Timer/sipSTSLValidateSessRefreshMsg: Ignoring 1xx response for session timer processing
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Info/sipSPISendInviteResponse: Associated container=0x710FD444 to Invite Response 100
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Transport/sipSPITransportSendMessage: msg=0x715D49CC, addr=80.251.131.133, port=5061, sentBy_port=5061, local_addr=, is_req=0, transport=1, switch=0, callBack=0x0
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x715D49CC to default port=5061
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetAgeingTimer: Aging timer initiated for holder=0x695DB1E0,addr=80.251.131.133
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnHolder: Created new holder=0x695DB1E0, addr=80.251.131.133; nailed=FALSE
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostRequestConnection: Posting UDP conn create request for addr=80.251.131.133, port=5061, context=0x70771354
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer: Wait timer set for connection=0x70772FF4,addr=80.251.131.133, port=5061
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportSetConnWaitTimer:
Wait Conn Timer started for 5000 msec
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipCreateConnInstance: Created new initiated conn=0x70772FF4, connid=-1, addr=80.251.131.133, port=5061, local_addr=, transport=UDP
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.133, rport:5061 with laddr:
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Transport/sipInstanceGetConnectionId: Registering gcb=0x713784D8 with connection=0x70772FF4
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Transport/sipTransportLogicSendMsg: Waiting for Connection for sending msg=0x715D49CC
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Transport/sipSPITransportSendMessage: Deferred sending msg=0x715D49CC
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/State/sipSPIChangeState: 0x713784D8 : State change from (STATE_IDLE, SUBSTATE_NONE) to (STATE_RECD_INVITE, SUBSTATE_NONE)
*Jun 25 14:34:40.399: //24/3B7405BEA62E/SIP/Info/sipSPIProcessContactInfo: Previous Hop 80.251.131.133:5061
*Jun 25 14:34:40.399: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_PROCEEDING
*Jun 25 14:34:40.403: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x71372D10) with key=[166] to table
*Jun 25 14:34:40.403: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization: Entry...
*Jun 25 14:34:40.403: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
*Jun 25 14:34:40.403: //25/000000000000/SIP/State/sipSPIChangeState: 0x71372D10 : State change from (STATE_NONE, SUBSTATE_NONE) to (STATE_IDLE, SUBSTATE_NONE)
*Jun 25 14:34:40.403: //25/000000000000/SIP/Info/ccsip_call_setup_request: Set Protocol information
*Jun 25 14:34:40.403: //25/000000000000/SIP/Info/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 2004 RTP/AVP 8 0 18 4 101
c=IN IP4 80.251.131.28
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=fmtp:4 bitrate=6.3;annexa=yes
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
*Jun 25 14:34:40.499: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
*Jun 25 14:34:40.499: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Jun 25 14:34:40.499: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
*Jun 25 14:34:40.499: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Jun 25 14:34:40.499: //25/3B7405BEA62E/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
Call-ID: 3411DD19-DCDB11E2-80DA93BC-5853A7A8@80.251.131.28
Content-Length: 0
CSeq: 101 INVITE
From: <4996540000>;tag=C83AC0-2F2
To: <4996540908>
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bKB455
*Jun 25 14:34:40.499: //25/3B7405BEA62E/SIP/Info/sipSPICheckResponseExt: INVITE response with no RSEQ - disable IS_REL1XX
*Jun 25 14:34:40.499: //25/3B7405BEA62E/SIP/State/sipSPIChangeState: 0x71372D10 : State change from (STATE_SENT_INVITE, SUBSTATE_NONE) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING)
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [80.251.131.27]:5060, local_address:[ - ]
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 183 Session Progress
Call-ID: 3411DD19-DCDB11E2-80DA93BC-5853A7A8@80.251.131.28
Content-Length: 226
Content-Type: application/sdp
CSeq: 101 INVITE
From: <4996540000>;tag=C83AC0-2F2
Require: 100rel
RSeq: 7000
To: <4996540908>;tag=50fb831b-a2
User-Agent: Quintum/1.0.0 SN/0030E1103326
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bKB455
Quintum: 070e0000000c00000006001e03808081
v=0
o=Quintum 87 3467 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10342 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
Router#
a=sendrecv
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Error/sipSPICheckReliableProvStringtag: Unable to access supported header values
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 10342
SIP: Attribute mid, level 1 instance 1 not found.
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved
as its in use by other codec No Codec
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is reserved by another application
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711alaw
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of full named event(NE) match in fmtp list of events.
*Jun 25 14:34:41.595: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIGetSDPDirectionAttribute: No direction attribute present or multiple direction attributes that can't be handled for m-line:1 and num-a-lines:0
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoAudioNegotiation: Codec negotiation successful for media line 1
payload_type=8, codec_bytes=160, codec=g711alaw, dtmf_relay=rtp-nte
stream_type=voice+dtmf (1), dest_ip_address=80.251.131.27, dest_port=10342
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/State/sipSPIChangeStreamState: Stream (callid = -1) State changed from (STREAM_DEAD) to (STREAM_ADDING)
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Media/sipSPIReplaceSDP: Main stream got changed & it's Flow Around
*Jun 25 14:34:41.595: //25/3B7405BEA62E/SIP/Media/sipSPIUpdCallWithSdpInfo:
Preferred Codec : g711alaw, bytes :160
Preferred DTMF relay : rtp-nte
Preferred NTE payload : 101
Early Media : No
Delayed Media : No
Bridge Done : No
New Media : No
DSP DNLD Reqd : No
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 80.251.131.28
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 25 peer 24 flags 0x400045 state STATE_RECD_PROCEEDING
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_vcc_ProcessXcoderNeeded: xcoder_attached not yet initialised for this call.
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Xcoder not yet used for the call
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CallID 25, Peer CallID 24, sdp 0x69368B8C channels 0x713742AC
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/copy_channels:
callId 25 size 924 ptr 0x71610728)
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB t38 version 0 ipip_caps version 0
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
CCB fax rate 32 ipip_caps rate 9600
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: reset the switch..
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 8 mline 1
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Selecting codec g711alaw
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/codec_found:
Codec to be matched: 6
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160, coverted ptime=20 stream->mline_index=1, media_ndx=1
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Adding codec 6 ptype 8 time 20, bytes 160 as channel 0 mline 1 ss 1 80.251.131.27:10342
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo:
Hndl ptype 101 mline 1
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: setting ipip_caps DTMF to RFC2833: callid = 25, dtmf = 6
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: Unable to find the proper instance for FMTP
SIP: fmtp attribute, level 1 instance 0 not found.
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Error/sipSPI_ipip_copy_sdp_to_channelInfo: Unable to acquire event mask for rfc2833 dtmf relay
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = 6
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[channel_ndx].codec = -1
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Updating tagdata..
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
callId 25 flags 0x10000100 state STATE_RECD_PROCEEDING
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Reporting media in Substate SUBSTATE_PROCEEDING_PROCEEDING
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer:
Report initial call media
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0x440018, ccb->pld.flags_ipip 0x400045
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Updating the negotiated codec bytes
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: Post CAPS to peer.
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_caps_ind_internal:
destCallID=24, srcCallID=25,
peer_ccb->call_info.currentLocalName=,
peer_ccb->call_info.currentRemoteName=,
ccb->call_info.currentLocalName=,
ccb->call_info.currentRemoteName=
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_get_rtcp_session_parameters: CURRENT VALUES: stream_callid=-1, current_seq_num=0x2122
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_get_rtcp_session_parameters: NEW VALUES: stream_callid=-1, current_seq_num=0x0
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_update_stream_negotiated_codec: Codec that peer call leg has indicated is same what this call leg is already using.. Do nothing..
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_caps_ind_internal: Load DSP with negotiated codec: g711alaw, Bytes=160
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_caps_ind_internal: Set forking flag to 0x0
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sipSPISetDTMFRelayMode: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_NTE_AND_OOB with rx payload = 96, tx payload = 96
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sip_set_modem_caps: Preferred (or the one that came from DSM) modem relay=0, from CLI config=0
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=25
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sip_set_modem_caps: Disabling Modem Relay...
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sip_set_modem_caps: Negotiation already Done. Set negotiated Modem caps and generate SDP Xcap list
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sip_set_modem_caps: Modem Relay & Passthru both disabled
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sip_set_modem_caps: nse payload = 0, ptru mode = 0, ptru-codec=2, redundancy=0, xid=0, rel
Router#ay=0, sprt-retry=12, latecncy=200, compres-dir=3, dict=1024, strnlen=32
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Media/sipSPISetStreamInfo: 0 Active Streams
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Media/sipSPISetStreamInfo: Number of active streams is zero (0)!
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Media/sipSPISetStreamInfo:
caps.stream_count=0,caps.stream[0].stream_type=0xFFFF, caps.stream_list.xmitFunc=
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Media/sipSPISetStreamInfo: ??unknown??, caps.stream_list.context=
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Media/sipSPISetStreamInfo: 0x0 (gccb)
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_caps_ind_internal: Load DSP with codec : g711alaw, Bytes=160, payload = 0
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_caps_ind_internal: ccsip_caps_ind: ccb->pld.flags_ipip = 0x400443
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/sipSPISrtpTranscoder:
Checking if transcoder is needed for SRTP-RTP
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_caps_ind_internal: No video caps detected in the caps posted by peer leg
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_caps_ind_internal: Calling cc_api_caps_ack()
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/ccsip_caps_ack_internal: Set forking flag to 0x0
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: ccb->flags 0x440018, ccb->pld.flags_ipip 0x400045
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/copy_channels:
callId 25 size 240 ptr 0x70F0BAA4)
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 165)
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_event_handler:
ccsip_event_handler: peer ID 25 chans 0x70F0BAA4 event 165 flags 0x40001C 0x10000100 0x400443 data 0x70F0BAA4
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_event_handler:
ccsip_event_handler: CC_EV_H245_OPEN_CHANNEL_IND: peer ID 25 chans 0x70F0BAA4 event 165 flags 0x40001C 0x10000100 0x400443 data 0x70F0BAA4
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_NEW_MEDIA
*Jun 25 14:34:41.599: //24/3B7405BEA62E/SIP/Info/ccsip_event_handler:
ccsip_event_handler: set event->type = SIPSPI_EV_CC_NEW_MEDIA!: peer ID 25 chans 0x70F0BAA4 event 165 flags 0x40001C 0x10000100 0x400443 data 0x70F0BAA4 Media Trigger 0
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_report_media_to_peer: SIP2SIP, posting channel_ind to peer.
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/ccsip_update_srtp_caps: 7392: Not Sending NULL SRTP CAPS to SIP LEG
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Media/sipSPIUpdCallWithSdpInfo:
Stream type : voice+dtmf
Media line : 1
State : STREAM_ADDING (2)
Stream address type : 1
Callid : 25
Negotiated Codec : g711alaw, bytes :160
Nego. Codec payload : 8 (tx), 8 (rx)
Negotiated DTMF relay : rtp-nte
Negotiated NTE payload : 101 (tx), 101 (rx)
Negotiated CN payload : 0
Media Srce Addr/Port : [80.251.131.28]:17264
Media Dest Addr/Port : [80.251.131.27]:10342
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Error/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled: - 0
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Error/ccsip_api_call_cut_progress: Unable to add headers
into container
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: switch(ev.ev_id: 100)
*Jun 25 14:34:41.599: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_event_handler: CC_R_SUCCESS_WITH_CONFIRMED
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/HandleSIP1xxSessionProgress: ccsip_api_call_cut_progress returned: SIP_SUCCESS
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/State/sipSPIChangeState: 0x71372D10 : State change from (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING) to (STATE_RECD_PROCEEDING, SUBSTATE_PROCEEDING_PROCEEDING)
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Error/sipSPIRel1xxCheck: Error in Contact/RR query launch in 18x
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/ccsip_set_cc_cause_for_spi_err: Categorized cause:47, category:180
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/ccsip_set_release_source_for_peer: ownCallId[25], src[6]
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 3 event
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
*Jun 25 14:34:41.599: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_GetPassthruCopyListDataFromTdContainer: Could not get any elements from TD Container
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Info/sipSPISendCancel: Associated container=0x710FC3C4 to Cancel
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Transport/sipSPISendCancel: Sending CANCEL to the transport layer
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Transport/sipSPITransportSendMessage: msg=0x71572210, addr=80.251.131.27, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x61B5EE7C
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
*Jun 25 14:34:41.603: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:80.251.131.27, rport:5060 with laddr:
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x71572210
*Jun 25 14:34:41.603: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x71572210, addr=80.251.131.27, port=5060, local_addr=, connId=3 for UDP
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Info/sentCancelInitiateDisconnect: Sent Cancel Request, starting CancelWaitResponseTimer
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Info/sipSPIInitiateDisconnect: Initiate call disconnect(47) for outgoing call
*Jun 25 14:34:41.603: //-1/xxxxxxxxxxxx/SIP/Error/sipSPIGetContentQSIG: No Inbound Container Created !!!
*Jun 25 14:34:41.603: //-1/xxxxxxxxxxxx/SIP/Error/sipSPIGetContentQ931: No Inbound Container Created !!!
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Error/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Invalid CCB/Data/Container
*Jun 25 14:34:41.603: //25/3B7405BEA62E/SIP/Error/sipAddSipContainerToCallEntry: Unable to add passthru hdrs
to containerACK sip:0008014996540908@80.251.131.28;user=phone SIP/2.0
Via: SIP/2.0/UDP 80.251.131.133:5061;rport;branch=z9hG4bK-110469435-3792809181-436258723-408012644
From: <4996540000>;tag=1046978875-3792809181-436258723-408012644
To: <0008014996540908>;tag=C83F84-4A4
Call-ID: 3ba1675cddac11e2a3c7001a64c75118@80.251.131.133
CSeq: 1 ACK
Max-Forwards: 70
User-Agent: MERA MVTS3G v.4.4.0-15
Content-Length: 0
*Jun 25 14:34:42.571: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
*Jun 25 14:34:42.571: //-1/xxxxxxxxxxxx/SIP/Error/sipSPISipIncomingMsg: Invalid method for (STATE_IDLE): ACK
Router#
*Jun 25 14:35:13.859: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[166] removed.
*Jun 25 14:35:13.859: //25/3B7405BEA62E/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
*Jun 25 14:35:13.859: //25/3B7405BEA62E/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x71372D10 key=3411DD19-DCDB11E2-80DA93BC-5853A7A8@80.251.131.28
*Jun 25 14:35:13.859: //25/3B7405BEA62E/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
*Jun 25 14:35:13.859: //25/3B7405BEA62E/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
Router#
*Jun 25 14:35:13.859: //25/3B7405BEA62E/SIP/Info/ccsip_offer_ans_delete:
*Jun 25 14:35:13.859: //25/3B7405BEA62E/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 71372D10
Router#
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-25-2013 08:34 AM
Yes debug ccsip all impacts on the router and makes the router churns our repetitive logs. I asked for
debug ccsip messages...
So please turn off debug ccsip all and enable only the above debug..Attach it here, dont paste it
Please rate all useful posts
"opportunity is a haughty goddess who waste no time with those who are unprepared"
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-25-2013 08:42 AM
Please teach me how to attach... :-(
Last debug seems to be correct. Router became quiet and I tried again.
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-26-2013 02:57 AM
Dear Aokanlawon!
I'm not sure I understood you. 5061 is a port from which RTU sends SIP commands (it's usual SIP port, not TLS). Which "other device" do you mean? What "destination" do you mean? And where can I change the values?
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-26-2013 03:38 AM
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-26-2013 10:07 AM
I have looked at the trace and What I see is that CUBE is sending CANCEL after receiving 183 session progress from Quintum...
Received:
SIP/2.0 183 Session Progress
Call-ID: A858991F-DD7A11E2-810A93BC-5853A7A8@80.251.131.28
Content-Length: 227
Content-Type: application/sdp
CSeq: 101 INVITE
From: <4996540000>;tag=4DD3A88-242B
Require: 100rel
RSeq: 7000
To: <4996540908>;tag=50fb831b-ba
User-Agent: Quintum/1.0.0 SN/0030E1103326
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK13D2F
Quintum: 070e0000000c00000006001e03808081
v=0
o=Quintum 103 7050 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10358 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
a=sendrecv
Sent:
CANCEL sip:4996540908@80.251.131.27:5060 SIP/2.0
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK13D2F
From: <4996540000>;tag=4DD3A88-242B
To: <4996540908>
Date: Wed, 26 Jun 2013 09:36:05 GMT
Call-ID: A858991F-DD7A11E2-810A93BC-5853A7A8@80.251.131.28
CSeq: 101 CANCEL
Max-Forwards: 70
Timestamp: 1372239366
Reason: Q.850;cause=47
Content-Length: 0
The reason CUBE is doing this is Cause code 47--which implies resource unavailable. The question is which resource does CUBE need..It is not clear.
The only place to see this is in the debug ccsip all. Please take another log and do it only when the gateway is not busy so we dont loose any packets or traces.
Please before you enable the debug..configure the following
service timestamps debug
logging buffered 10000000 debug
no logging console
no logging monitor
default logging rate-limit
default logging queue-limit
service sequence-numbers
Enable the debug, do a test and use putty or any terminal application to collect the debug..Then run the command
term len 0
show loggin
Please rate all useful posts
"opportunity is a haughty goddess who waste no time with those who are unprepared"
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-26-2013 11:12 AM
I think the issue here is the Invite from CUCM doesn't have 100rel supported but the outbound Invite to the PSTN does so the PSTN sends a 183 Session Progress with SDP. The CUBE knows CUCM can't handle this and therefor sends the Cancel with cause code 47. There's 2 ways to fix this. You can either enable Prack in the CUCM SIP Profile under SIP Rel1XX Options. You can set this to Send Prack if 1xx Contains SDP. That way CUCM will send rel1xx as supported in its outgoing Invite to the CUBE and thus the CUBE will forward the 183 Session Progress appropriately and get a PRACK back from CUCM. The other option would be disabling outbound rel1xx advertisement on the CUBE. You can do this on the outbound dial-peer by running "voice-class sip rel1xx disable".
Thanks,
Brian Meade
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-26-2013 01:15 PM
Brian,
There is no CUCM in the picture. There are two sip endpoints sitting aside the CUBE
Quitum----sip---CUBE-----sip----RTU Soft switch
The originator of the call is the RTU soft switch. This endpoint does not require PRACK..The endpoint that requires PRACK is Quintum and since CUBE supports it, I dont see why CUBE shouldnt responding to it.
In the INVITE that CUBE sent to Quintum, we can see it advertising support for 100rel
Sent:
INVITE sip:4996540908@80.251.131.27:5060 SIP/2.0
Via: SIP/2.0/UDP 80.251.131.28:5060;branch=z9hG4bK13D2F
Remote-Party-ID: <4996540000>;party=calling;screen=yes;privacy=off
From: <4996540000>;tag=4DD3A88-242B
To: <4996540908>
Date: Wed, 26 Jun 2013 09:36:05 GMT
Call-ID: A858991F-DD7A11E2-810A93BC-5853A7A8@80.251.131.28
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
This is what is puzzling because rather than CUBE sending PRACK on receipt of 100rel required in 183 session progress, it sends a CANCEL
Please rate all useful posts
"opportunity is a haughty goddess who waste no time with those who are unprepared"
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-26-2013 01:37 PM
Sorry, I keep forgetting there's no CUCM. Yes, the CUBE should be sending that PRACK regardless of what happens on the RTU soft switch side.
There must be something about the SDP in the session progress that the CUBE doesn't like.
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
06-26-2013 01:48 PM
The rtpmap for G.711alaw has encoding parameter set even though there's only 1 audio channel. This is within RFC 4566 but definitely isn't common.
Here's the SDP:
v=0
o=Quintum 103 7050 IN IP4 80.251.131.27
s=VoipCall
c=IN IP4 80.251.131.27
t=0 0
m=audio 10358 RTP/AVP 8 101
c=IN IP4 80.251.131.27
a=rtpmap:8 pcma/8000/1
a=ptime:20
a=rtpmap:101 telephone-event/8000/1
a=sendrecv
I found a similar issue when the encoding parameter was set and the CUBE not liking it. An upgrade resolved the issue.
Ellad,
What IOS version is on the CUBE?
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide