Buy or Renew
Buy or Renew
Cisco + Splunk: It’s a new day for your data. Learn more.
 
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
1089
Views
0
Helpful
2
Replies

UC520 Call issues With SIP Trunk

jkaranitsch
Level 1
Level 1

‎06-21-2019 08:25 AM

I'm having trouble configuring my UC520 to make calls via my sip provider. After configuration the SIP trunk with CCA, the SIP dial peer was not found. After googeling around and read many pages and tuning the configuration file by hand the dial peer is found, but Inbound or outbound calls are not working. Here are debug ccsip all for an inbound and an outbound call:

 
Labels:
0 Helpful
2 Replies 2

jkaranitsch
Level 1
Level 1

‎06-21-2019 08:26 AM

Inbound call:

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2019.06.21 12:42:14 =~=~=~=~=~=~=~=~=~=~=~=
000429: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id F
000430: Jun 21 12:34:33.434: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[13] removed.
000431: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
000432: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A73DF8 key=b2fad331-16d58a74-85d25a6@193.84.65.820720123456
000433: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
000434: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
000435: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
000436: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/ccsip_offer_ans_delete:
000437: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/ccsip_iwf_delete: 
000438: Jun 21 12:34:33.434: //15/EB2FEB0E8012/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A73DF8
000439: Jun 21 10:34:40.238: %IPPHONE-6-REGISTER: ephone-4:SEPA45630BB065A IP:10.1.1.18 Socket:9 DeviceType:Phone has registered.
000440: Jun 21 12:34:41.442: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
000441: Jun 21 12:34:41.442: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
000442: Jun 21 12:34:41.442: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x88181B48
000443: Jun 21 12:34:41.442: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x88181B48, addr=193.84.65.82, port=5060, local_addr=, connid=2, transport=UDP
000444: Jun 21 12:34:41.442: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
OPTIONS sip:0720123456@10.200.207.19:5060 SIP/2.0
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK6233628
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-97fd1641
To: sip:0720123456@10.200.207.19:5060
Call-ID: b2fad331-7bd58a74-08d25a6@193.84.65.82
CSeq: 1 OPTIONS
Content-Length: 0
 

000445: Jun 21 12:34:41.442: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
000446: Jun 21 12:34:41.442: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A73DF8) with key=[16] to table
000447: Jun 21 12:34:41.446: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
000448: Jun 21 12:34:41.446: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
000449: Jun 21 12:34:41.446: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
000450: Jun 21 12:34:41.446: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
000451: Jun 21 12:34:41.446: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000452: Jun 21 12:34:41.446: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000453: Jun 21 12:34:41.446: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000454: Jun 21 12:34:41.446: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000455: Jun 21 12:34:41.446: //-1/030A197E8018/SIP/State/sipSPIChangeState: 0x88A73DF8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
000456: Jun 21 12:34:41.446: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000457: Jun 21 12:34:41.446: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
000458: Jun 21 12:34:41.446: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000459: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/ccsipInitPldCallingInfo: non-numeric calling number: hello
000460: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:193.84.65.82:5060, Host:193.84.65.82
000461: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : hello
000462: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
000463: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
000464: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
000465: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/sipSPIGetCallConfig: Peer tag 1000 matched for incoming call
000466: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
000467: Jun 21 12:34:41.446: //18/030A197E8018/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
000468: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000469: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000470: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000471: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
000472: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
000473: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
000474: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
000475: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
000476: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
000477: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE
000478: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
000479: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
000480: Jun 21 12:34:41.450: //18/030A197E8018/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
000481: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPIGetCallConfig: Media forking disabled
000482: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
000483: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
000484: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
000485: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
000486: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
000487: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000488: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
000489: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.200.207.19
000490: Jun 21 12:34:41.450: //18/030A197E8018/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
000491: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000492: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000493: Jun 21 12:34:41.450: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000494: Jun 21 12:34:41.454: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_OPTIONS_RESP
000495: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Info/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS
000496: Jun 21 12:34:41.454: //18/030A197E8018/SIP/State/sipSPIChangeState: 0x88A73DF8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE)
000497: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
000498: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A73DF8 key=b2fad331-7bd58a74-08d25a6@193.84.65.820720123456
000499: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 12 to table
000500: Jun 21 12:34:41.454: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 38
000501: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Info/sipSPISendOptionsResponse: Associated container=0x8986B5A4 to Options Response
000502: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Transport/sipSPITransportSendMessage: msg=0x86618CBC, addr=193.84.65.82, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x814B105C
000503: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
000504: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
000505: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x86618CBC to default port=5060
000506: Jun 21 12:34:41.454: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
000507: Jun 21 12:34:41.454: //18/030A197E8018/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x86618CBC
000508: Jun 21 12:34:41.454: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x86618CBC, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
000509: Jun 21 12:34:41.458: //18/030A197E8018/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK6233628
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-97fd1641
To: sip:0720123456@10.200.207.19:5060;tag=3737C-525
Date: Fri, 21 Jun 2019 10:34:41 GMT
Call-ID: b2fad331-7bd58a74-08d25a6@193.84.65.82
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 OPTIONS
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Accept: application/sdp
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Content-Type: application/sdp
Content-Length: 456
 
v=0
o=CiscoSystemsSIP-GW-UserAgent 6121 8078 IN IP4 10.200.207.19
s=SIP Call
c=IN IP4 10.200.207.19
t=0 0
m=audio 0 RTP/AVP 18 0 8 9 4 2 15 3
c=IN IP4 10.200.207.19
m=image 0 udptl t38
c=IN IP4 10.200.207.19
a=T38FaxVersion:0
a=T38MaxBitRate:9600
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:320
a=T38FaxUdpEC:t38UDPRedundancy

000510: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A68A18) with key=[17] to table
000511: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
000512: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
000513: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
000514: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
000515: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: p2p mode with Registrar Server = dns:bvoip.at
000516: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/ccsipRegisterSetTargetInfo: Parsing The Registrar Address
000517: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : bvoip.at target_port : 5060
000518: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: outbound_host : p03.neotel.at outbound_port : 5060
000519: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/sipSPIOutboundProxyReuse: Do not reuse Outbound Proxy IP adress and Port
000520: Jun 21 12:34:51.490: //-1/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
000521: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/ccsip_spi_registrar_add_expires_header: Inside ccsip_spi_registrar_add_expires_header for Expires
000522: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_OUTBOUND_REGISTER
000523: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIIncrementOverloadCount: Local 1 Global 1
000524: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 40
000525: Jun 21 12:34:51.490: //-1/000000000000/SIP/Info/act_idle_outgoing_register: In act_idle_outgoing_register
000526: Jun 21 12:34:51.490: //19/000000000000/SIP/Info/act_idle_outgoing_register:  Send REGISTER to p03.neotel.at:5060
000527: Jun 21 12:34:51.490: //19/000000000000/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
000528: Jun 21 12:34:51.490: //19/000000000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A68A18 key=9553C513-934611E9-8002FC79-894ABFDB
000529: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_DNS_RESOLVE
000530: Jun 21 12:34:51.490: //19/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_SENT_DNS)
000531: Jun 21 12:34:51.490: //19/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS)  to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_SENT_DNS)
000532: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: TYPE SRV query for _sip._udp.p03.neotel.at and type:1
000533: Jun 21 12:34:51.490: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Server Name p03.neotel.at
000534: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Priority 0 Weight 5 Port 5060
000535: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Calculating Random Number : 64125 factor 13107 value 4
000536: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Selected Server is p03.neotel.at
000537: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: TYPE A query successful for p03.neotel.at
000538: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: ttl for A records = 419 seconds
000539: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: IP Address of p03.neotel.at is:
000540: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: 193.84.65.82
000541: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: ttl for SRV records = 419 seconds
000542: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 43
000543: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: sipSPICacheHostToCCB dnsResponse.num_hosts = 1
000544: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: IP Address No. 1, IP address 193.84.65.82
000545: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000546: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000547: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000548: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_api_register_target_dns_resolved: ttl = 419
000549: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_spi_register_get_rcb: Getting New RCB [0x89699F80]
000550: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_register_set_dns_resolved_address: CCSIP_REGISTER:: registrar 0 DNS resolved addr set to 193.84.65.82:5060
000551: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/ccsipRegisterStartRCBTimer: Starting timer for pattern  for 3600 seconds
000552: Jun 21 12:34:51.494: //19/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_SENT_DNS)  to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
000553: Jun 21 12:34:51.494: //19/000000000000/SIP/Info/sipSPIPresendProcessing: Presend Processing called for 7 event
000554: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
000555: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIRetrieveOutgoingPassThruData: Retrieving Data from RCB
000556: Jun 21 12:34:51.494: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
000557: Jun 21 12:34:51.494: //19/000000000000/SIP/Info/sipSPISendRegister: Associated container=0x8986AAFC to Register
000558: Jun 21 12:34:51.498: //19/000000000000/SIP/Transport/sipSPISendRegister: Sending REGISTER to the transport layer
000559: Jun 21 12:34:51.498: //19/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
000560: Jun 21 12:34:51.498: //19/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x86619060, addr=193.84.65.82, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x814B0F70
000561: Jun 21 12:34:51.498: //19/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
000562: Jun 21 12:34:51.498: //19/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
000563: Jun 21 12:34:51.498: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
000564: Jun 21 12:34:51.498: //19/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x86619060
000565: Jun 21 12:34:51.498: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x86619060, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
000566: Jun 21 12:34:51.498: //19/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)  to (SIP_STATE_OUTGOING_REGISTER, SUBSTATE_NONE)
000567: Jun 21 12:34:51.498: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
REGISTER sip:bvoip.at:5060 SIP/2.0
Via: SIP/2.0/UDP 10.200.207.19:5060;branch=z9hG4bK61DB2
From: <sip:2*@bvoip.at>;tag=39ABC-22D2
To: <sip:2*@bvoip.at>
Date: Fri, 21 Jun 2019 10:34:51 GMT
Call-ID: 9553C513-934611E9-8002FC79-894ABFDB
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
Timestamp: 1561113291
CSeq: 3 REGISTER
Contact: <sip:2*@10.200.207.19:5060>
Expires:  3600
Supported: path
Content-Length: 0
 

000568: Jun 21 12:34:51.510: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
000569: Jun 21 12:34:51.510: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
000570: Jun 21 12:34:51.510: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
000571: Jun 21 12:34:51.510: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
000572: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK61DB2 from via branch list
000573: Jun 21 12:34:51.514: //19/000000000000/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 404 Unknown User
Via: SIP/2.0/UDP 10.200.207.19:5060;branch=z9hG4bK61DB2
From: <sip:2*@bvoip.at>;tag=39ABC-22D2
To: <sip:2*@bvoip.at>;tag=7c692e931e158521a59b51071af7a4de.af76
Call-ID: 9553C513-934611E9-8002FC79-894ABFDB
CSeq: 3 REGISTER
Content-Length: 0
 

000574: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX
000575: Jun 21 12:34:51.514: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDecrementOverloadCount: Count:Local 0 Global 0
000576: Jun 21 12:34:51.514: //19/000000000000/SIP/Error/ccsip_api_register_result_ind: Message Code Class 4xx Method Code 100 received for REGISTER
000577: Jun 21 12:34:51.514: //-1/xxxxxxxxxxxx/SIP/Info/ccsipGetCCBFromRCB: Retrived CCB pointer [0x0]
000578: Jun 21 12:34:51.514: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_spi_register_free_rcb: Freeing rcb [0x89699F80]
000579: Jun 21 12:34:51.514: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_register_reset_dns_cache: CCSIP_REGISTER:: registrar 0 DNS resolved addr reset
000580: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/sipSPIRegPthruProcessResponse: Processing response w/ resp code == 404
000581: Jun 21 12:34:51.514: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetRPCBFromRCB: Retreiving RCB [0x89C52168] from RPCB [0x0]
000582: Jun 21 12:34:51.514: //19/000000000000/SIP/Error/sipSPIRegPthruProcessResponse: Error NO RPCB
000583: Jun 21 12:34:51.514: //-1/xxxxxxxxxxxx/SIP/Info/ccsipRegisterStartRCBTimer: Starting timer for pattern 2* for 180 seconds
000584: Jun 21 12:34:51.514: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[17] removed.
000585: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
000586: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A68A18 key=9553C513-934611E9-8002FC79-894ABFDB
000587: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
000588: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
000589: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/ccsip_offer_ans_delete:
000590: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/ccsip_iwf_delete: 
000591: Jun 21 12:34:51.514: //19/000000000000/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A68A18
000592: Jun 21 12:34:51.514: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[17]
000593: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 11
000594: Jun 21 12:34:53.451: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[15] removed.
000595: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
000596: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A797E8 key=b2fad331-c8d58a74-c6d25a6@193.84.65.820720123456
000597: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
000598: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
000599: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
000600: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/ccsip_offer_ans_delete:
000601: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/ccsip_iwf_delete: 
000602: Jun 21 12:34:53.451: //17/F71D9EBA8017/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A797E8
000603: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
000604: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
000605: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x88181B48
000606: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x88181B48, addr=193.84.65.82, port=5060, local_addr=, connid=2, transport=UDP
000607: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
OPTIONS sip:0720123456@10.200.207.19:5060 SIP/2.0
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK9388784
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-4afd1641
To: sip:0720123456@10.200.207.19:5060
Call-ID: b2fad331-2ed58a74-49d25a6@193.84.65.82
CSeq: 1 OPTIONS
Content-Length: 0
 

000608: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
000609: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A797E8) with key=[18] to table
000610: Jun 21 12:35:01.451: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
000611: Jun 21 12:35:01.451: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
000612: Jun 21 12:35:01.451: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
000613: Jun 21 12:35:01.451: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
000614: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000615: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000616: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000617: Jun 21 12:35:01.451: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000618: Jun 21 12:35:01.451: //-1/0EF694428019/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
000619: Jun 21 12:35:01.455: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000620: Jun 21 12:35:01.455: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
000621: Jun 21 12:35:01.455: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000622: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/ccsipInitPldCallingInfo: non-numeric calling number: hello
000623: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:193.84.65.82:5060, Host:193.84.65.82
000624: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : hello
000625: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
000626: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
000627: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
000628: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPIGetCallConfig: Peer tag 1000 matched for incoming call
000629: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
000630: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
000631: Jun 21 12:35:01.455: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000632: Jun 21 12:35:01.455: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000633: Jun 21 12:35:01.455: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000634: Jun 21 12:35:01.455: //20/0EF694428019/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
000635: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
000636: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
000637: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
000638: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
000639: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
000640: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE
000641: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
000642: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
000643: Jun 21 12:35:01.459: //20/0EF694428019/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
000644: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPIGetCallConfig: Media forking disabled
000645: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
000646: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
000647: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
000648: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
000649: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
000650: Jun 21 12:35:01.459: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000651: Jun 21 12:35:01.459: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
000652: Jun 21 12:35:01.459: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.200.207.19
000653: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
000654: Jun 21 12:35:01.459: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000655: Jun 21 12:35:01.459: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000656: Jun 21 12:35:01.459: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000657: Jun 21 12:35:01.459: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_OPTIONS_RESP
000658: Jun 21 12:35:01.459: //20/0EF694428019/SIP/Info/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS
000659: Jun 21 12:35:01.459: //20/0EF694428019/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE)
000660: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
000661: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A797E8 key=b2fad331-2ed58a74-49d25a6@193.84.65.820720123456
000662: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 14 to table
000663: Jun 21 12:35:01.463: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 38
000664: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Info/sipSPISendOptionsResponse: Associated container=0x8986AC5C to Options Response
000665: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Transport/sipSPITransportSendMessage: msg=0x8AE83C14, addr=193.84.65.82, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x814B105C
000666: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
000667: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
000668: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x8AE83C14 to default port=5060
000669: Jun 21 12:35:01.463: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
000670: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x8AE83C14
000671: Jun 21 12:35:01.463: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x8AE83C14, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
000672: Jun 21 12:35:01.463: //20/0EF694428019/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK9388784
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-4afd1641
To: sip:0720123456@10.200.207.19:5060;tag=3C1A4-E3B
Date: Fri, 21 Jun 2019 10:35:01 GMT
Call-ID: b2fad331-2ed58a74-49d25a6@193.84.65.82
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 OPTIONS
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Accept: application/sdp
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Content-Type: application/sdp
Content-Length: 456
 
v=0
o=CiscoSystemsSIP-GW-UserAgent 2399 9870 IN IP4 10.200.207.19
s=SIP Call
c=IN IP4 10.200.207.19
t=0 0
m=audio 0 RTP/AVP 18 0 8 9 4 2 15 3
c=IN IP4 10.200.207.19
m=image 0 udptl t38
c=IN IP4 10.200.207.19
a=T38FaxVersion:0
a=T38MaxBitRate:9600
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:320
a=T38FaxUdpEC:t38UDPRedundancy

000673: Jun 21 12:35:09.967: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
000674: Jun 21 12:35:09.967: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
000675: Jun 21 12:35:09.967: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x88181B48
000676: Jun 21 12:35:09.967: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x88181B48, addr=193.84.65.82, port=5060, local_addr=, connid=2, transport=UDP
000677: Jun 21 12:35:09.967: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:43720123456@10.200.207.19:5060 SIP/2.0
Record-Route: <sip:193.84.65.82;lr;ftag=0UUHS0000030000E1D02031u1AOIVML1SWNTCZ;vsf=AAAAAAAAAAAAAAAAAAAAABEfH1lJABUGdW5rO3gtc3JjPXRkbQ--;x-rtpp=1>
Via: SIP/2.0/UDP 193.84.65.82;branch=z9hG4bK3437.dcc72ffbc359f246c2ee5ddbe6117c89.0
Via: SIP/2.0/UDP 192.168.46.235:5060;branch=z9hG4bKPAQA0iwsgA
Via: SIP/2.0/UDP 192.168.46.235:5060;branch=z9hG4bKZkkc0hz7Vg;internal=5050800-1
From: "06801234567" <sip:06801234567@bvoip.at>;tag=0UUHS0000030000E1D02031u1AOIVML1SWNTCZ
To: <sip:+43720123456@bvoip.at>
Call-ID: 2a15e00013f5-5d0cb48d-1e11c66e-21c7cbf0-3a172d5-01-UASession-XdJxwqPM1I
CSeq: 1 INVITE
Max-Forwards: 67
Supported: timer
Unsupported: refer,hold
Allow: INVITE,ACK,CANCEL,BYE,INFO,REGISTER,SUBSCRIBE
Contact: <sip:192.168.46.235:5060;internal=5050800-1>
Content-Length: 288
Content-Type: application/sdp
Record-Route: <sip:192.168.46.235:5060;transport=udp;lr>
Allow-Events: talk
Accept: application/sdp
 
v=0
o=- 435988533133091157 1 IN IP4 193.84.65.207
s=TELES-SBC
c=IN IP4 193.84.65.207
t=0 0
m=audio 27060 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=silenceSupp:off - - - -
a=sendrecv
a=rtcp:27061

000678: Jun 21 12:35:09.967: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
000679: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A68A18) with key=[19] to table
000680: Jun 21 12:35:09.971: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
000681: Jun 21 12:35:09.971: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
000682: Jun 21 12:35:09.971: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
000683: Jun 21 12:35:09.971: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
000684: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000685: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000686: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000687: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000688: Jun 21 12:35:09.971: //-1/140AAB32801A/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
000689: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000690: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
000691: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000692: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000693: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000694: Jun 21 12:35:09.971: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000695: Jun 21 12:35:09.971: //-1/140AAB32801A/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
000696: Jun 21 12:35:09.971: //-1/140AAB32801A/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
000697: Jun 21 12:35:09.975: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
000698: Jun 21 12:35:09.975: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container
000699: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
000700: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A68A18 key=2a15e00013f5-5d0cb48d-1e11c66e-21c7cbf0-3a172d5-01-UASession-XdJxwqPM1I43720123456
000701: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
000702: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 43720123456
000703: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 06801234567
000704: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name 06801234567, number 06801234567, Calling oct3 0x00, oct_3a 0x80, Called number 43720123456
000705: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:193.84.65.82:5060, Host:193.84.65.82
000706: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 06801234567
000707: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
000708: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
000709: Jun 21 12:35:09.975: //-1/140AAB32801A/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
000710: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIGetCallConfig: Peer tag 1000 matched for incoming call
000711: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
000712: Jun 21 12:35:09.979: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000713: Jun 21 12:35:09.979: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000714: Jun 21 12:35:09.979: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000715: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
000716: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
000717: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
000718: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
000719: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
000720: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE
000721: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
000722: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
000723: Jun 21 12:35:09.979: //-1/140AAB32801A/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
000724: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIGetCallConfig: Media forking disabled
000725: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
000726: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
000727: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
000728: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
000729: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIContinueNewMsgInvite: Calling name 06801234567, number 06801234567, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number 43720123456, oct3 0x00
000730: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
000731: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIValidateRequestUri: Not Enabled
000732: Jun 21 12:35:09.979: //-1/140AAB32801A/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
000733: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled:  - 0
000734: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
000735: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:8986A99C
000736: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Not received session expires header
000737: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ
000738: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_LEG_BY_LEG, SE Value:0, SE Refresher:none, Min-SE Value:1800, flags:2001
000739: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Info/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:2001, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
000740: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
000741: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
000742: Jun 21 12:35:09.979: //21/140AAB32801A/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
000743: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
000744: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 27060
SIP: (21) Attribute mid, level 1 instance 1 not found.
000745: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
000746: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000747: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
000748: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.200.207.19
000749: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
000750: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec  
000751: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96
000752: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved
                          as its in use by other codec No Codec  
000753: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is  reserved by another application
000754: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
000755: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101
000756: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:
000757: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1
000758: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
000759: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160
000760: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
000761: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711alaw
000762: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0
000763: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
000764: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec
000765: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec
000766: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
000767: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE
000768: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
000769: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events.
000770: Jun 21 12:35:09.983: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0
000771: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
000772: Jun 21 12:35:09.983: //21/140AAB32801A/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
000773: Jun 21 12:35:09.983: //21/140AAB32801A/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=193.84.65.207, dest_port=27060
000774: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/State/sipSPIChangeStreamState: Stream (callid =  -1)  State changed from (STREAM_DEAD) to (STREAM_ADDING)
000775: Jun 21 12:35:09.983: //21/140AAB32801A/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
000776: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
000777: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
000778: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
000779: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp:
000780: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/Info/ccsip_offer_ans_process_event:
000781: Jun 21 12:35:09.983: //21/140AAB32801A/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_INVITE_SDP_RCVD
000782: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/ccsip_offer_ans_is_invite_offer_valid:  - 1
000783: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/ccsip_offer_ans_common_offer_rcvd_hdlr:
000784: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/ccsip_iwf_handle_network_event:
000785: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/ccsip_iwf_process_event: 
000786: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_RCVD_SDP
000787: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_def_ed_rcvd_sdp_hdlr:
000788: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo:
CallID 21, sdp 0x86626528 channels 0x88A6A06C
000789: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/copy_channels:
 callId 21 size 0 ptr 0x883EFE9C)
000790: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPI_ipip_copy_and_init_channelInfo_params:
 CCB t38 version 0 ipip_caps version 0
000791: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPI_ipip_copy_and_init_channelInfo_params:
 CCB fax rate 2 ipip_caps rate 14400
000792: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: stream_callid = 21, peer_stream_callid = -1
000793: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo:
Hndl ptype 8 mline 1
000794: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Selecting codec g711alaw
000795: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/codec_found:
Codec to be matched: 6
000796: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/codec_found:  codecs[i] = 6 & codec = 6 are same..
000797: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6
000798: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo:
000799: Jun 21 12:35:09.987: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
000800: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo:
Adding negotiated codec 6 ptype 8 time 20,   bytes 160 as channel 0 mline 1 ss 0 193.84.65.207:27060
000801: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Error/sipSPI_ipip_update_codec_params_in_channelInfo:
failed to update call entry
000802: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160,stream->mline_index=1, media_ndx=1
000803: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
000804: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Selecting codec g711ulaw
000805: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/codec_found:
Codec to be matched: 5
000806: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/codec_found: No match for the codecs found..
000807: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo:
Hndl ptype 101 mline 1
000808: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPI_ipip_update_dynamic_codec_params:
000809: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPI_ipip_upd_2833_dtmf_params:
000810: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPI_ipip_upd_2833_dtmf_params: setting ipip_caps DTMF to RFC2833: callid = 21, dtmf = 6
000811: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Error/sipSPI_ipip_update_call_entry:
failed to update call entry
000812: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[0].codec = 6
000813: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[1].codec = -1
000814: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: srcChannelID = -1, dstChannelID = 21
000815: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Media/sipSPIDisplayStreamInfo:
  Stream type            : voice+dtmf
  Media line             : 1
  State                  : STREAM_ADDING (2)
  Stream address type    : 1
  Callid                 : 21
  Peer Callid            : -1
  RTP/SRTP Negotiated     : 8
  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   : [10.200.207.19]:0
  Media Dest Addr/Port   : [193.84.65.207]:27060
000816: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPI_ipip_calculate_channel_count: Number of streams to report = 1
000817: Jun 21 12:35:09.987: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_set_channel_count: Unable to set CHANNEL_COUNT for callid 21
000818: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Error/sip_iwf_sip_copy_sdp_to_channelInfo: Channel count is not set at this point. Not SIP-SIP or SET_MODE is not done.
000819: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_RCVD_AWAIT_PEER_EVENT
000820: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_RCVD
000821: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Media/sipSPIUpdCallWithSdpInfo:
  Stream type            : voice+dtmf
  Media line             : 1
  State                  : STREAM_ADDING (2)
  Stream address type    : 1
  Callid                 : 21
  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   : [10.200.207.19]:0
  Media Dest Addr/Port   : [193.84.65.207]:27060
000822: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPIHandleInviteMedia:
Negotiated Codec       : g711alaw, bytes :160
Preferred Codec        : g711alaw, bytes :160
Preferred  DTMF relay 1 : 6
Preferred  DTMF relay 2 : 0
Negotiated DTMF relay   : 6
Preferred and Negotiated NTE payloads: 101 101
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
000823: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
000824: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
000825: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
000826: Jun 21 12:35:09.987: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 18652 for stream 1
000827: Jun 21 12:35:09.987: //21/140AAB32801A/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=18652
000828: Jun 21 12:35:09.987: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
000829: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 18652
000830: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
 SIP update src sdp, negoitated codec 6, payload type 8
000831: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 101
000832: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 16
000833: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 2a15e00013f5-5d0cb48d-1e11c66e-21c7cbf0-3a172d5-01-UASession-XdJxwqPM1I
000834: Jun 21 12:35:09.991: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
000835: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
000836: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
000837: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue
000838: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled:  - 0
000839: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
000840: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/ccsip_api_call_setup_ind: Unable to add unsupp headers to container
000841: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/ccsip_api_call_setup_ind: Set Protocol information
000842: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 24
000843: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
000844: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
000845: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
000846: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 6,
000847: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Media/sipSPIDisplayStreamInfo:
  Stream type            : voice+dtmf
  Media line             : 1
  State                  : STREAM_ADDING (2)
  Stream address type    : 1
  Callid                 : 21
  Peer Callid            : -1
  RTP/SRTP Negotiated     : 8
  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   : [10.200.207.19]:18652
  Media Dest Addr/Port   : [193.84.65.207]:27060
000848: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_calculate_channel_count: Number of streams to report = 1
000849: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPI_ipip_store_channel_info: Setting CHANNEL_COUNT = 1 for callid 21
000850: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIShrlCall: Check peer: 1000 for Shared-Line call, callid: 21
000851: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/ccsip_set_bearer_capability:
   Bearer Capability: Speech (0x00)
000852: Jun 21 12:35:09.991: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
000853: Jun 21 12:35:09.991: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
000854: Jun 21 12:35:09.991: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message
000855: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_INTERNAL_ERR
000856: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIContinueNewMsgInvite: Application Layer internal request
000857: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
000858: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A68A18 key=2a15e00013f5-5d0cb48d-1e11c66e-21c7cbf0-3a172d5-01-UASession-XdJxwqPM1I3E2FC-1297
000859: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
000860: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:500, container:8986A7E4
000861: Jun 21 12:35:09.991: //21/140AAB32801A/SIP/Info/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:1, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
000862: Jun 21 12:35:09.995: //21/140AAB32801A/SIP/Info/sipSPISendInviteResponse: Associated container=0x8986A7E4 to Invite Response 500
000863: Jun 21 12:35:09.995: //21/140AAB32801A/SIP/Transport/sipSPITransportSendMessage: msg=0x8AEAD1A0, addr=193.84.65.82, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x814AC8F4
000864: Jun 21 12:35:09.995: //21/140AAB32801A/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
000865: Jun 21 12:35:09.995: //21/140AAB32801A/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
000866: Jun 21 12:35:09.995: //21/140AAB32801A/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x8AEAD1A0 to default port=5060
000867: Jun 21 12:35:09.995: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
000868: Jun 21 12:35:09.995: //21/140AAB32801A/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x8AEAD1A0
000869: Jun 21 12:35:09.995: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x8AEAD1A0, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
000870: Jun 21 12:35:09.995: //21/140AAB32801A/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response
000871: Jun 21 12:35:09.995: //21/140AAB32801A/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_DISCONNECTING, SUBSTATE_NONE)
000872: Jun 21 12:35:09.999: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 500 Internal Server Error
Via: SIP/2.0/UDP 193.84.65.82;branch=z9hG4bK3437.dcc72ffbc359f246c2ee5ddbe6117c89.0,SIP/2.0/UDP 192.168.46.235:5060;branch=z9hG4bKPAQA0iwsgA,SIP/2.0/UDP 192.168.46.235:5060;branch=z9hG4bKZkkc0hz7Vg;internal=5050800-1
From: "06801234567" <sip:06801234567@bvoip.at>;tag=0UUHS0000030000E1D02031u1AOIVML1SWNTCZ
To: <sip:+43720123456@bvoip.at>;tag=3E2FC-1297
Date: Fri, 21 Jun 2019 10:35:09 GMT
Call-ID: 2a15e00013f5-5d0cb48d-1e11c66e-21c7cbf0-3a172d5-01-UASession-XdJxwqPM1I
CSeq: 1 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0
 

000896: Jun 21 12:35:10.011: //21/140AAB32801A/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A68A18
000897: Jun 21 12:35:10.011: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[19]
000898: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A68A18) with key=[20] to table
000899: Jun 21 12:35:11.499: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
000900: Jun 21 12:35:11.499: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
000901: Jun 21 12:35:11.499: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
000902: Jun 21 12:35:11.499: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
000903: Jun 21 12:35:11.499: //22/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
000904: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 37
000905: Jun 21 12:35:11.499: //22/000000000000/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 16 to table
000906: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_DNS_RESOLVE
000907: Jun 21 12:35:11.499: //22/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_SENT_DNS)
000908: Jun 21 12:35:11.499: //22/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_SENT_DNS)
000909: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: TYPE SRV query for _sip._udp.p03.neotel.at and type:1
000910: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Server Name p03.neotel.at
000911: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Priority 0 Weight 5 Port 5060
000912: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Calculating Random Number : 60012 factor 13107 value 4
000913: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Selected Server is p03.neotel.at
000914: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: TYPE A query successful for p03.neotel.at
000915: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: ttl for A records = 399 seconds
000916: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: IP Address of p03.neotel.at is:
000917: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: 193.84.65.82
000918: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: ttl for SRV records = 399 seconds
000919: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 43
000920: Jun 21 12:35:11.499: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: sipSPICacheHostToCCB dnsResponse.num_hosts = 1
000921: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: IP Address No. 1, IP address 193.84.65.82
000922: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000923: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000924: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000925: Jun 21 12:35:11.503: //22/000000000000/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (SIP_STATE_OPTIONS_WAIT, SUBSTATE_SENT_DNS)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE)
000926: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000927: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000928: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000929: Jun 21 12:35:11.503: //22/000000000000/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
000930: Jun 21 12:35:11.503: //22/000000000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A68A18 key=14F47230-934711E9-801EFC79-894ABFDB@bvoip.at
000931: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
000932: Jun 21 12:35:11.503: //22/000000000000/SIP/Error/sipSPIAddPrivacyHeader: Orig Container is NULL...should have value
000933: Jun 21 12:35:11.503: //22/000000000000/SIP/Error/sipSPIAddAssertedIDHeader: Orig Container is NULL...should have value
000934: Jun 21 12:35:11.503: //22/000000000000/SIP/Error/sipSPIAddPreferredIDHeader: Orig Container is NULL...should have value
000935: Jun 21 12:35:11.503: //22/000000000000/SIP/Info/sipSPISendOptionsRequest: Associated container=0x8986A7E4 to Options
000936: Jun 21 12:35:11.503: //22/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
000937: Jun 21 12:35:11.503: //22/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x8AE83FB8, addr=193.84.65.82, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x814B0FEC
000938: Jun 21 12:35:11.503: //22/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
000939: Jun 21 12:35:11.503: //22/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
000940: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
000941: Jun 21 12:35:11.503: //22/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x8AE83FB8
000942: Jun 21 12:35:11.503: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x8AE83FB8, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
000943: Jun 21 12:35:11.503: //22/000000000000/SIP/Msg/ccsipDisplayMsg:
Sent:
OPTIONS sip:p03.neotel.at:5060 SIP/2.0
Via: SIP/2.0/UDP 10.200.207.19:5060;branch=z9hG4bK78A6
From: <sip:bvoip.at>;tag=3E8E4-97B
To: <sip:p03.neotel.at>
Date: Fri, 21 Jun 2019 10:35:11 GMT
Call-ID: 14F47230-934711E9-801EFC79-894ABFDB@bvoip.at
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
CSeq: 101 OPTIONS
Contact: <sip:10.200.207.19:5060>
Content-Length: 0
 

000944: Jun 21 12:35:11.515: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
000945: Jun 21 12:35:11.515: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
000946: Jun 21 12:35:11.515: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
000947: Jun 21 12:35:11.515: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
000948: Jun 21 12:35:11.515: //22/000000000000/SIP/Info/sipSPIMatchRespToReqTran: removing unneeded z9hG4bK78A6 from via branch list
000949: Jun 21 12:35:11.515: //22/000000000000/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 Keepalive
Via: SIP/2.0/UDP 10.200.207.19:5060;branch=z9hG4bK78A6
From: <sip:bvoip.at>;tag=3E8E4-97B
To: <sip:p03.neotel.at>;tag=7c692e931e158521a59b51071af7a4de.f28d
Call-ID: 14F47230-934711E9-801EFC79-894ABFDB@bvoip.at
CSeq: 101 OPTIONS
Content-Length: 0
 

000950: Jun 21 12:35:11.515: //22/000000000000/SIP/Info/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX
000951: Jun 21 12:35:11.515: //22/000000000000/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 16
000952: Jun 21 12:35:11.515: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[20] removed.
000953: Jun 21 12:35:11.515: //22/000000000000/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
000954: Jun 21 12:35:11.515: //22/000000000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A68A18 key=14F47230-934711E9-801EFC79-894ABFDB@bvoip.at
000955: Jun 21 12:35:11.515: //22/000000000000/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
000956: Jun 21 12:35:11.519: //22/000000000000/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
000957: Jun 21 12:35:11.519: //22/000000000000/SIP/Info/ccsip_offer_ans_delete:
000958: Jun 21 12:35:11.519: //22/000000000000/SIP/Info/ccsip_iwf_delete: 
000959: Jun 21 12:35:11.519: //22/000000000000/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A68A18
000960: Jun 21 12:35:11.519: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[20]
000961: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 12
000962: Jun 21 12:35:13.455: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[16] removed.
000963: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
000964: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A73DF8 key=b2fad331-7bd58a74-08d25a6@193.84.65.820720123456
000965: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
000966: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
000967: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
000968: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/ccsip_offer_ans_delete:
000969: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/ccsip_iwf_delete: 
000970: Jun 21 12:35:13.455: //18/030A197E8018/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A73DF8
000971: Jun 21 12:35:21.456: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
000972: Jun 21 12:35:21.456: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
000973: Jun 21 12:35:21.456: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x88181B48
000974: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x88181B48, addr=193.84.65.82, port=5060, local_addr=, connid=2, transport=UDP
000975: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
OPTIONS sip:0720123456@10.200.207.19:5060 SIP/2.0
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK2069129
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-fcfd1641
To: sip:0720123456@10.200.207.19:5060
Call-ID: b2fad331-d0e58a74-8ad25a6@193.84.65.82
CSeq: 1 OPTIONS
Content-Length: 0
 

000976: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
000977: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A73DF8) with key=[21] to table
000978: Jun 21 12:35:21.460: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
000979: Jun 21 12:35:21.460: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
000980: Jun 21 12:35:21.460: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
000981: Jun 21 12:35:21.460: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
000982: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000983: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
000984: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
000985: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
000986: Jun 21 12:35:21.460: //-1/1AE3AB2D801F/SIP/State/sipSPIChangeState: 0x88A73DF8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
000987: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000988: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
000989: Jun 21 12:35:21.460: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
000990: Jun 21 12:35:21.460: //23/1AE3AB2D801F/SIP/Info/ccsipInitPldCallingInfo: non-numeric calling number: hello
000991: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:193.84.65.82:5060, Host:193.84.65.82
000992: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : hello
000993: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
000994: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
000995: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
000996: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetCallConfig: Peer tag 1000 matched for incoming call
000997: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
000998: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
000999: Jun 21 12:35:21.464: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001000: Jun 21 12:35:21.464: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001001: Jun 21 12:35:21.464: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001002: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
001003: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
001004: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
001005: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
001006: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
001007: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
001008: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE
001009: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
001010: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
001011: Jun 21 12:35:21.464: //23/1AE3AB2D801F/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
001012: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIGetCallConfig: Media forking disabled
001013: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
001014: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
001015: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
001016: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
001017: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
001018: Jun 21 12:35:21.464: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001019: Jun 21 12:35:21.464: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
001020: Jun 21 12:35:21.464: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.200.207.19
001021: Jun 21 12:35:21.464: //23/1AE3AB2D801F/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
001022: Jun 21 12:35:21.468: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001023: Jun 21 12:35:21.468: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001024: Jun 21 12:35:21.468: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001025: Jun 21 12:35:21.468: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_OPTIONS_RESP
001026: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Info/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS
001027: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/State/sipSPIChangeState: 0x88A73DF8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE)
001028: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
001029: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A73DF8 key=b2fad331-d0e58a74-8ad25a6@193.84.65.820720123456
001030: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 17 to table
001031: Jun 21 12:35:21.468: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 38
001032: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Info/sipSPISendOptionsResponse: Associated container=0x8986B54C to Options Response
001033: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Transport/sipSPITransportSendMessage: msg=0x898976EC, addr=193.84.65.82, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x814B105C
001034: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
001035: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
001036: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x898976EC to default port=5060
001037: Jun 21 12:35:21.468: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
001038: Jun 21 12:35:21.468: //23/1AE3AB2D801F/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x898976EC
001039: Jun 21 12:35:21.468: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x898976EC, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
001040: Jun 21 12:35:21.472: //23/1AE3AB2D801F/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK2069129
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-fcfd1641
To: sip:0720123456@10.200.207.19:5060;tag=40FC8-16C8
Date: Fri, 21 Jun 2019 10:35:21 GMT
Call-ID: b2fad331-d0e58a74-8ad25a6@193.84.65.82
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 OPTIONS
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Accept: application/sdp
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Content-Type: application/sdp
Content-Length: 456
 
v=0
o=CiscoSystemsSIP-GW-UserAgent 5893 4634 IN IP4 10.200.207.19
s=SIP Call
c=IN IP4 10.200.207.19
t=0 0
m=audio 0 RTP/AVP 18 0 8 9 4 2 15 3
c=IN IP4 10.200.207.19
m=image 0 udptl t38
c=IN IP4 10.200.207.19
a=T38FaxVersion:0
a=T38MaxBitRate:9600
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:320
a=T38FaxUdpEC:t38UDPRedundancy

001041: Jun 21 12:35:22.988: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
001042: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
001043: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x88181B48
001044: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x88181B48, addr=193.84.65.82, port=5060, local_addr=, connid=2, transport=UDP
001045: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:4372012345612@10.200.207.19:5060 SIP/2.0
Record-Route: <sip:193.84.65.82;lr;ftag=0UUHS0000030000E1D02031u1APP0ML103IK8Q;vsf=AAAAAAAAAAAAAAAAAAAAABEfH1lJABUGdW5rO3gtc3JjPXRkbQ--;x-rtpp=1>
Via: SIP/2.0/UDP 193.84.65.82;branch=z9hG4bKf197.1cae44a86e73e653b02df54aec52c6f3.0
Via: SIP/2.0/UDP 192.168.46.235:5060;branch=z9hG4bKp9m1E7bjav
Via: SIP/2.0/UDP 192.168.46.235:5060;branch=z9hG4bKVJMu~l06!U;internal=5050800-1
From: "06801234567" <sip:06801234567@bvoip.at>;tag=0UUHS0000030000E1D02031u1APP0ML103IK8Q
To: <sip:+4372012345612@bvoip.at>
Call-ID: 2a15e00013f5-5d0cb49a-58111e54-22fcb9e0-3a17339-01-UASession-bS2RPPA2uQ
CSeq: 1 INVITE
Max-Forwards: 67
Supported: timer
Unsupported: refer,hold
Allow: INVITE,ACK,CANCEL,BYE,INFO,REGISTER,SUBSCRIBE
Contact: <sip:192.168.46.235:5060;internal=5050800-1>
Content-Length: 288
Content-Type: application/sdp
Record-Route: <sip:192.168.46.235:5060;transport=udp;lr>
Allow-Events: talk
Accept: application/sdp
 
v=0
o=- 436001553562099023 1 IN IP4 193.84.65.207
s=TELES-SBC
c=IN IP4 193.84.65.207
t=0 0
m=audio 27206 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=silenceSupp:off - - - -
a=sendrecv
a=rtcp:27207

001046: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
001047: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A68A18) with key=[22] to table
001048: Jun 21 12:35:22.992: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
001049: Jun 21 12:35:22.992: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
001050: Jun 21 12:35:22.992: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
001051: Jun 21 12:35:22.992: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
001052: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
001053: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001054: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001055: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001056: Jun 21 12:35:22.992: //-1/1BCD6EF48020/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
001057: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
001058: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
001059: Jun 21 12:35:22.992: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
001060: Jun 21 12:35:22.996: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001061: Jun 21 12:35:22.996: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001062: Jun 21 12:35:22.996: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001063: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
001064: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/sipSPICheckAssertedIdConfig: Dialpeer match is not yet done
001065: Jun 21 12:35:22.996: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentGTD: No GTD found in inbound container
001066: Jun 21 12:35:22.996: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCSTA: No CSTA found in inbound container
001067: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
001068: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A68A18 key=2a15e00013f5-5d0cb49a-58111e54-22fcb9e0-3a17339-01-UASession-bS2RPPA2uQ4372012345612
001069: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on carrier id
001070: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on Incoming called number: 4372012345612
001071: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/sipSPIMatchSrcIpGroup: Match not found on destination pattern: 06801234567
001072: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/ccsipUpdateIncomingCallParams: ccCallInfo: Calling name 06801234567, number 06801234567, Calling oct3 0x00, oct_3a 0x80, Called number 4372012345612
001073: Jun 21 12:35:22.996: //-1/1BCD6EF48020/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:193.84.65.82:5060, Host:193.84.65.82
001074: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : 06801234567
001075: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
001076: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
001077: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
001078: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetCallConfig: Peer tag 1000 matched for incoming call
001079: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
001080: Jun 21 12:35:23.000: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001081: Jun 21 12:35:23.000: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001082: Jun 21 12:35:23.000: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001083: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
001084: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
001085: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
001086: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
001087: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
001088: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE
001089: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
001090: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
001091: Jun 21 12:35:23.000: //-1/1BCD6EF48020/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
001092: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIGetCallConfig: Media forking disabled
001093: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
001094: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
001095: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
001096: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
001097: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIContinueNewMsgInvite: Calling name 06801234567, number 06801234567, Calling oct3 0x00, oct_3a 0x80, ext_priv 0x00, Called number 4372012345612, oct3 0x00
001098: Jun 21 12:35:23.000: //-1/1BCD6EF48020/SIP/Info/sipSPIContinueNewMsgInvite: Carrier id code , prev_cid NONE, next_cid NONE, prev_tgrp NONE, next_tgrp NONE
001099: Jun 21 12:35:23.004: //-1/1BCD6EF48020/SIP/Info/sipSPIValidateRequestUri: Not Enabled
001100: Jun 21 12:35:23.004: //-1/1BCD6EF48020/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
001101: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_IsSDPPassthruEnabled:  - 0
001102: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
001103: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Event/Session-Timer/sipSTSLMain: dir:2, method:102, resp_code:0, container:8986A9F4
001104: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/Session-Timer/sipSTSLExtractSessionExpiresHdr: Not received session expires header
001105: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/Session-Timer/sipSTSLGetInternalSREvent: E_STSL_INITIAL_SR_REQ
001106: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Event/Session-Timer/sipSTSLPrintTDContainer: Peer-Event: E_STSL_LEG_BY_LEG, SE Value:0, SE Refresher:none, Min-SE Value:1800, flags:2001
001107: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:2001, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
001108: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPIProcessHistoryInfoHeader: No HI headers recvd from app container
001109: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPIProcessDiversionHeader: No diversion headers recvd from app container
001110: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPIProcessReplacesHeader: No replaces hdr found
001111: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPIDoMediaNegotiation: Number of m-lines = 1
001112: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPIValidateConnectionAddress: Dest port = 27206
SIP: (24) Attribute mid, level 1 instance 1 not found.
001113: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
001114: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001115: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
001116: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.200.207.19
001117: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
001118: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec No Codec  
001119: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 96
001120: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) could not be reserved
                          as its in use by other codec No Codec  
001121: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPT: Requested payload-Type (101) is  reserved by another application
001122: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
001123: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 101
001124: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAllocateFreeDynamicPT: Allocating free Dynamic Payload : 98 for Codec:
001125: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPIDoAudioNegotiation: Codec (g711alaw) Negotiation Successful on Static Payload for m-line 1
001126: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPIDoPtimeNegotiation: One ptime attribute found - value:20
001127: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/convert_ptime_to_codec_bytes: Values :Codec: g711alaw ptime :20, codecbytes: 160
001128: Jun 21 12:35:23.004: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
001129: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Media/sipSPIDoPtimeNegotiation: Offered ptime:20, Negotiated ptime:20 Negotiated codec bytes: 160 for codec g711alaw
001130: Jun 21 12:35:23.004: //24/1BCD6EF48020/SIP/Info/sipSPISetFaxFlags: FAX_PASSTHROUGH = 0, END_FAX_PASSTHROUGH = 0
001131: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPIDoDTMFRelayNegotiation: m-line index 1
001132: Jun 21 12:35:23.008: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec
001133: Jun 21 12:35:23.008: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICheckDynPayloadUse: Dynamic payload(101) reserved for codec
001134: Jun 21 12:35:23.008: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIUpdateDynamicPayloadunused: Unreserving dynamic payload type 98
001135: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPIReserveRtpNtePayload: Reserved the payload type 101 for RTP-NTE
001136: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPIDoDTMFRelayNegotiation: RTP-NTE DTMF relay option
001137: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPIDoDTMFRelayNegotiation: Case of partial named event(NE) match in fmtp list of events.
001138: Jun 21 12:35:23.008: //-1/xxxxxxxxxxxx/SIP/Info/sip_sdp_get_modem_relay_cap_params: V150 NSE payload = 0, SSE payload = 0, SPRT payload=0
001139: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_select_modem_relay_params: X-tmr not present in SDP. Disable modem relay
001140: Jun 21 12:35:23.008: //24/1BCD6EF48020/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
001141: Jun 21 12:35:23.008: //24/1BCD6EF48020/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=193.84.65.207, dest_port=27206
001142: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/State/sipSPIChangeStreamState: Stream (callid =  -1)  State changed from (STREAM_DEAD) to (STREAM_ADDING)
001143: Jun 21 12:35:23.008: //24/1BCD6EF48020/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
001144: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
001145: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
001146: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
001147: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/ccsip_offer_ans_handle_rcvd_sdp:
001148: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/ccsip_offer_ans_process_event:
001149: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_INVITE_SDP_RCVD
001150: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/ccsip_offer_ans_is_invite_offer_valid:  - 1
001151: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/ccsip_offer_ans_common_offer_rcvd_hdlr:
001152: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/ccsip_iwf_handle_network_event:
001153: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/ccsip_iwf_process_event: 
001154: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_RCVD_SDP
001155: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_def_ed_rcvd_sdp_hdlr:
001156: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo:
CallID 24, sdp 0x8661984C channels 0x88A6A06C
001157: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/copy_channels:
 callId 24 size 0 ptr 0x883EFE9C)
001158: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_copy_and_init_channelInfo_params:
 CCB t38 version 0 ipip_caps version 0
001159: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_copy_and_init_channelInfo_params:
 CCB fax rate 2 ipip_caps rate 14400
001160: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: stream_callid = 24, peer_stream_callid = -1
001161: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo:
Hndl ptype 8 mline 1
001162: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Selecting codec g711alaw
001163: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/codec_found:
Codec to be matched: 6
001164: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/codec_found:  codecs[i] = 6 & codec = 6 are same..
001165: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: ADD AUDIO CODEC 6
001166: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo:
001167: Jun 21 12:35:23.008: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
001168: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_update_codec_params_in_channelInfo:
Adding negotiated codec 6 ptype 8 time 20,   bytes 160 as channel 0 mline 1 ss 0 193.84.65.207:27206
001169: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Error/sipSPI_ipip_update_codec_params_in_channelInfo:
failed to update call entry
001170: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Media negotiation done: stream->negotiated_ptime=20,stream->negotiated_codec_bytes=160,stream->mline_index=1, media_ndx=1
001171: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo:
Hndl ptype 0 mline 1
001172: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Selecting codec g711ulaw
001173: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/codec_found:
Codec to be matched: 5
001174: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/codec_found: No match for the codecs found..
001175: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo:
Hndl ptype 101 mline 1
001176: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_update_dynamic_codec_params:
001177: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_upd_2833_dtmf_params:
001178: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_upd_2833_dtmf_params: setting ipip_caps DTMF to RFC2833: callid = 24, dtmf = 6
001179: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Error/sipSPI_ipip_update_call_entry:
failed to update call entry
001180: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[0].codec = 6
001181: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: Copy sdp to channel- AFTER CODEC FILTERING: ccb->pld.ipip_caps.codecInfo[1].codec = -1
001182: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sip_iwf_sip_copy_sdp_to_channelInfo: srcChannelID = -1, dstChannelID = 24
001183: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Media/sipSPIDisplayStreamInfo:
  Stream type            : voice+dtmf
  Media line             : 1
  State                  : STREAM_ADDING (2)
  Stream address type    : 1
  Callid                 : 24
  Peer Callid            : -1
  RTP/SRTP Negotiated     : 8
  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   : [10.200.207.19]:0
  Media Dest Addr/Port   : [193.84.65.207]:27206
001184: Jun 21 12:35:23.008: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_calculate_channel_count: Number of streams to report = 1
001185: Jun 21 12:35:23.012: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_set_channel_count: Unable to set CHANNEL_COUNT for callid 24
001186: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Error/sip_iwf_sip_copy_sdp_to_channelInfo: Channel count is not set at this point. Not SIP-SIP or SET_MODE is not done.
001187: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_RCVD_AWAIT_PEER_EVENT
001188: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_RCVD
001189: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Media/sipSPIUpdCallWithSdpInfo:
  Stream type            : voice+dtmf
  Media line             : 1
  State                  : STREAM_ADDING (2)
  Stream address type    : 1
  Callid                 : 24
  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   : [10.200.207.19]:0
  Media Dest Addr/Port   : [193.84.65.207]:27206
001190: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIHandleInviteMedia:
Negotiated Codec       : g711alaw, bytes :160
Preferred Codec        : g711alaw, bytes :160
Preferred  DTMF relay 1 : 6
Preferred  DTMF relay 2 : 0
Negotiated DTMF relay   : 6
Preferred and Negotiated NTE payloads: 101 101
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
001191: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIDoQoSNegotiationWithMediaLine: QOS negotiation for mline_index 1
001192: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIDoStreamQoSNegotiation: Best effort
001193: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
001194: Jun 21 12:35:23.012: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 16494 for stream 1
001195: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIUpdateSrcSdpFixedPart: Reserving rtp port for stream 1, src_port=16494
001196: Jun 21 12:35:23.012: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
001197: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Setting stream 1 portnum to 16494
001198: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIUpdateSrcSdpVariablePart:
 SIP update src sdp, negoitated codec 6, payload type 8
001199: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIUpdateSrcSdpVariablePart: Negotiated method of dtmf relayand pyld: 6 101
001200: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIUpdateSrcSdpVariablePart: max_event 16
001201: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIAddBillingInfoToCcb: sipCallId for billing records = 2a15e00013f5-5d0cb49a-58111e54-22fcb9e0-3a17339-01-UASession-bS2RPPA2uQ
001202: Jun 21 12:35:23.012: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentCPA: No CPA found in inbound container
001203: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPIProcessCPA: No x-cisco-cpa content found
001204: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
001205: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_ExtractPassthruCopyListHdrsFromSipContainer: Unsupported header passthru is not configured and no headers are present in hdr_hash_queue
001206: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_IsContentPassthruEnabled:  - 0
001207: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_ExtractPassthruContentFromSipContainer: Passthru Content Not Enabled
001208: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/ccsip_api_call_setup_ind: Unable to add unsupp headers to container
001209: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/ccsip_api_call_setup_ind: Set Protocol information
001210: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/ccsip_ipip_media_service_get_event_data: Event id = 24
001211: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_antiTrombone: Entered Antitrombone service
001212: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_antiTrombone: Antitrombone service not configured
001213: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_store_channel_info: Store channelInfo in CallInfo
001214: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_store_channel_info: dtmf negotiation done, storing negotiated dtmf = 6,
001215: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Media/sipSPIDisplayStreamInfo:
  Stream type            : voice+dtmf
  Media line             : 1
  State                  : STREAM_ADDING (2)
  Stream address type    : 1
  Callid                 : 24
  Peer Callid            : -1
  RTP/SRTP Negotiated     : 8
  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   : [10.200.207.19]:16494
  Media Dest Addr/Port   : [193.84.65.207]:27206
001216: Jun 21 12:35:23.012: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_calculate_channel_count: Number of streams to report = 1
001217: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/sipSPI_ipip_store_channel_info: Setting CHANNEL_COUNT = 1 for callid 24
001218: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/sipSPIShrlCall: Check peer: 1000 for Shared-Line call, callid: 24
001219: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/ccsip_set_bearer_capability:
   Bearer Capability: Speech (0x00)
001220: Jun 21 12:35:23.016: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQSIG: No QSIG Body found in inbound container
001221: Jun 21 12:35:23.016: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContentQ931: No RawMsg Body found in inbound container
001222: Jun 21 12:35:23.016: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICreateNewRawMsg: No Data to form The Raw Message
001223: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/sipSPIContinueNewMsgInvite: ccsip_api_call_setup_ind returned: SIP_INTERNAL_ERR
001224: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/sipSPIContinueNewMsgInvite: Application Layer internal request
001225: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/sipSPIUaddCcbToUASRespTable: ****Adding to UAS Response table.
001226: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A68A18 key=2a15e00013f5-5d0cb49a-58111e54-22fcb9e0-3a17339-01-UASession-bS2RPPA2uQ415DC-19F2
001227: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_RESP
001228: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:500, container:8986A8EC
001229: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/Session-Timer/sipSTSLMain:
SE: 0;refresher:none peer refresher:none, flags:1, posted event:E_STSL_INVALID_PEER_EVENT, reason:4
Configured SE:1800, Configured Min-SE:1800
001230: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/sipSPISendInviteResponse: Associated container=0x8986A8EC to Invite Response 500
001231: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Transport/sipSPITransportSendMessage: msg=0x8AEAD104, addr=193.84.65.82, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x814AC8F4
001232: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
001233: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
001234: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x8AEAD104 to default port=5060
001235: Jun 21 12:35:23.016: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
001236: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x8AEAD104
001237: Jun 21 12:35:23.016: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x8AEAD104, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
001238: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/Info/sentErrResDisconnecting: Sent an 3456XX Error Response
001239: Jun 21 12:35:23.016: //24/1BCD6EF48020/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_DISCONNECTING, SUBSTATE_NONE)
001240: Jun 21 12:35:23.020: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
001264: Jun 21 12:35:23.032: //24/1BCD6EF48020/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A68A18
001265: Jun 21 12:35:23.036: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[22]
001266: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 14
001267: Jun 21 12:35:33.464: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[18] removed.
001268: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
001269: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A797E8 key=b2fad331-2ed58a74-49d25a6@193.84.65.820720123456
001270: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
001271: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
001272: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
001273: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/ccsip_offer_ans_delete:
001274: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/ccsip_iwf_delete: 
001275: Jun 21 12:35:33.464: //20/0EF694428019/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A797E8
UC520#
UC520#no debug all
All possible debugging has been turned off
UC520#terminal no monitor
UC520#
UC520#
0 Helpful

jkaranitsch
Level 1
Level 1

‎06-21-2019 08:27 AM

Outbound call:

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2019.06.21 12:45:08 =~=~=~=~=~=~=~=~=~=~=~=
UC520#terminal monitor
UC520#debug ccsip all
This may severely impact system performance. Continue? [confirm]
All SIP Call tracing is enabled
UC520#
001802: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 22
001803: Jun 21 12:38:13.510: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[31] removed.
001804: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
001805: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A68A18 key=b2fad331-a3f58a74-43e25a6@193.84.65.820720123456
001806: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
001807: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
001808: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
001809: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/ccsip_offer_ans_delete:
001810: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/ccsip_iwf_delete: 
001811: Jun 21 12:38:13.510: //34/6E5CDB008031/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A68A18
001812: Jun 21 12:38:21.518: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
001813: Jun 21 12:38:21.518: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
001814: Jun 21 12:38:21.518: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x88181B48
001815: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x88181B48, addr=193.84.65.82, port=5060, local_addr=, connid=2, transport=UDP
001816: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
OPTIONS sip:0720123456@10.200.207.19:5060 SIP/2.0
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK8127085
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-251e1641
To: sip:0720123456@10.200.207.19:5060
Call-ID: b2fad331-09f58a74-c5e25a6@193.84.65.82
CSeq: 1 OPTIONS
Content-Length: 0
 

001817: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
001818: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A68A18) with key=[34] to table
001819: Jun 21 12:38:21.522: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
001820: Jun 21 12:38:21.522: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
001821: Jun 21 12:38:21.522: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
001822: Jun 21 12:38:21.522: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
001823: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
001824: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001825: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001826: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001827: Jun 21 12:38:21.522: //-1/863708D78033/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
001828: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
001829: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
001830: Jun 21 12:38:21.522: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
001831: Jun 21 12:38:21.522: //37/863708D78033/SIP/Info/ccsipInitPldCallingInfo: non-numeric calling number: hello
001832: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:193.84.65.82:5060, Host:193.84.65.82
001833: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : hello
001834: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
001835: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
001836: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
001837: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetCallConfig: Peer tag 1000 matched for incoming call
001838: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
001839: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
001840: Jun 21 12:38:21.526: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001841: Jun 21 12:38:21.526: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001842: Jun 21 12:38:21.526: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001843: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
001844: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
001845: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
001846: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
001847: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
001848: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
001849: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE
001850: Jun 21 12:38:21.526: //37/863708D78033/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
001851: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
001852: Jun 21 12:38:21.526: //37/863708D78033/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
001853: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIGetCallConfig: Media forking disabled
001854: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
001855: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
001856: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
001857: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
001858: Jun 21 12:38:21.526: //37/863708D78033/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
001859: Jun 21 12:38:21.526: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001860: Jun 21 12:38:21.526: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
001861: Jun 21 12:38:21.526: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.200.207.19
001862: Jun 21 12:38:21.526: //37/863708D78033/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
001863: Jun 21 12:38:21.530: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001864: Jun 21 12:38:21.530: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001865: Jun 21 12:38:21.530: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001866: Jun 21 12:38:21.530: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_OPTIONS_RESP
001867: Jun 21 12:38:21.530: //37/863708D78033/SIP/Info/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS
001868: Jun 21 12:38:21.530: //37/863708D78033/SIP/State/sipSPIChangeState: 0x88A68A18 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE)
001869: Jun 21 12:38:21.530: //37/863708D78033/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
001870: Jun 21 12:38:21.530: //37/863708D78033/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A68A18 key=b2fad331-09f58a74-c5e25a6@193.84.65.820720123456
001871: Jun 21 12:38:21.530: //37/863708D78033/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 25 to table
001872: Jun 21 12:38:21.530: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 38
001873: Jun 21 12:38:21.530: //37/863708D78033/SIP/Info/sipSPISendOptionsResponse: Associated container=0x8986A41C to Options Response
001874: Jun 21 12:38:21.530: //37/863708D78033/SIP/Transport/sipSPITransportSendMessage: msg=0x8661A868, addr=193.84.65.82, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x814B105C
001875: Jun 21 12:38:21.530: //37/863708D78033/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
001876: Jun 21 12:38:21.530: //37/863708D78033/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
001877: Jun 21 12:38:21.530: //37/863708D78033/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x8661A868 to default port=5060
001878: Jun 21 12:38:21.530: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
001879: Jun 21 12:38:21.530: //37/863708D78033/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x8661A868
001880: Jun 21 12:38:21.530: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x8661A868, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
001881: Jun 21 12:38:21.542: //37/863708D78033/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK8127085
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-251e1641
To: sip:0720123456@10.200.207.19:5060;tag=6CF20-D03
Date: Fri, 21 Jun 2019 10:38:21 GMT
Call-ID: b2fad331-09f58a74-c5e25a6@193.84.65.82
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 OPTIONS
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Accept: application/sdp
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Content-Type: application/sdp
Content-Length: 456
 
v=0
o=CiscoSystemsSIP-GW-UserAgent 5889 3027 IN IP4 10.200.207.19
s=SIP Call
c=IN IP4 10.200.207.19
t=0 0
m=audio 0 RTP/AVP 18 0 8 9 4 2 15 3
c=IN IP4 10.200.207.19
m=image 0 udptl t38
c=IN IP4 10.200.207.19
a=T38FaxVersion:0
a=T38MaxBitRate:9600
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:320
a=T38FaxUdpEC:t38UDPRedundancy

001882: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A797E8) with key=[35] to table
001883: Jun 21 12:38:31.542: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
001884: Jun 21 12:38:31.542: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
001885: Jun 21 12:38:31.542: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
001886: Jun 21 12:38:31.542: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
001887: Jun 21 12:38:31.542: //39/000000000000/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
001888: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 37
001889: Jun 21 12:38:31.542: //39/000000000000/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 27 to table
001890: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_DNS_RESOLVE
001891: Jun 21 12:38:31.542: //39/000000000000/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_SENT_DNS)
001892: Jun 21 12:38:31.542: //39/000000000000/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_SENT_DNS)
001893: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: TYPE SRV query for _sip._udp.p03.neotel.at and type:1
001894: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Server Name p03.neotel.at
001895: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Priority 0 Weight 5 Port 5060
001896: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Calculating Random Number : 27002 factor 13107 value 2
001897: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Selected Server is p03.neotel.at
001898: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: TYPE A query successful for p03.neotel.at
001899: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: ttl for A records = 199 seconds
001900: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: IP Address of p03.neotel.at is:
001901: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: 193.84.65.82
001902: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: ttl for SRV records = 199 seconds
001903: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 43
001904: Jun 21 12:38:31.542: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: sipSPICacheHostToCCB dnsResponse.num_hosts = 1
001905: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: IP Address No. 1, IP address 193.84.65.82
001906: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001907: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001908: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001909: Jun 21 12:38:31.546: //39/000000000000/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (SIP_STATE_OPTIONS_WAIT, SUBSTATE_SENT_DNS)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE)
001910: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
001911: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
001912: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
001913: Jun 21 12:38:31.546: //39/000000000000/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
001914: Jun 21 12:38:31.546: //39/000000000000/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A797E8 key=8C30A1AE-934711E9-8038FC79-894ABFDB@bvoip.at
001915: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
001916: Jun 21 12:38:31.546: //39/000000000000/SIP/Error/sipSPIAddPrivacyHeader: Orig Container is NULL...should have value
001917: Jun 21 12:38:31.546: //39/000000000000/SIP/Error/sipSPIAddAssertedIDHeader: Orig Container is NULL...should have value
001918: Jun 21 12:38:31.546: //39/000000000000/SIP/Error/sipSPIAddPreferredIDHeader: Orig Container is NULL...should have value
001919: Jun 21 12:38:31.546: //39/000000000000/SIP/Info/sipSPISendOptionsRequest: Associated container=0x8986AB54 to Options
001920: Jun 21 12:38:31.546: //39/000000000000/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Global configuration, Switch Transport is FALSE
001921: Jun 21 12:38:31.546: //39/000000000000/SIP/Transport/sipSPITransportSendMessage: msg=0x86619604, addr=193.84.65.82, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x814B0FEC
001922: Jun 21 12:38:31.546: //39/000000000000/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
001923: Jun 21 12:38:31.546: //39/000000000000/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
001924: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
001925: Jun 21 12:38:31.546: //39/000000000000/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x86619604
001926: Jun 21 12:38:31.546: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x86619604, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
001927: Jun 21 12:38:31.546: //39/000000000000/SIP/Msg/ccsipDisplayMsg:
Sent:
OPTIONS sip:p03.neotel.at:5060 SIP/2.0
Via: SIP/2.0/UDP 10.200.207.19:5060;branch=z9hG4bKB3F9
From: <sip:bvoip.at>;tag=6F648-183A
To: <sip:p03.neotel.at>
Date: Fri, 21 Jun 2019 10:38:31 GMT
Call-ID: 8C30A1AE-934711E9-8038FC79-894ABFDB@bvoip.at
User-Agent: Cisco-SIPGateway/IOS-12.x
Max-Forwards: 70
CSeq: 101 OPTIONS
Contact: <sip:10.200.207.19:5060>
Content-Length: 0
 

001928: Jun 21 12:38:31.558: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
001929: Jun 21 12:38:31.558: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
001930: Jun 21 12:38:31.558: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x0
001931: Jun 21 12:38:31.558: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
001932: Jun 21 12:38:31.558: //39/000000000000/SIP/Info/sipSPIMatchRespToReqTran: removing unneeded z9hG4bKB3F9 from via branch list
001933: Jun 21 12:38:31.558: //39/000000000000/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 Keepalive
Via: SIP/2.0/UDP 10.200.207.19:5060;branch=z9hG4bKB3F9
From: <sip:bvoip.at>;tag=6F648-183A
To: <sip:p03.neotel.at>;tag=7c692e931e158521a59b51071af7a4de.4607
Call-ID: 8C30A1AE-934711E9-8038FC79-894ABFDB@bvoip.at
CSeq: 101 OPTIONS
Content-Length: 0
 

001934: Jun 21 12:38:31.558: //39/000000000000/SIP/Info/sipSPICheckResponseExt: non-INVITE response with no RSEQ - do not disable IS_REL1XX
001935: Jun 21 12:38:31.558: //39/000000000000/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 27
001936: Jun 21 12:38:31.558: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[35] removed.
001937: Jun 21 12:38:31.558: //39/000000000000/SIP/Info/sipSPIUdeleteCcbFromUACTable: ****Deleting from UAC table.
001938: Jun 21 12:38:31.558: //39/000000000000/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A797E8 key=8C30A1AE-934711E9-8038FC79-894ABFDB@bvoip.at
001939: Jun 21 12:38:31.558: //39/000000000000/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
001940: Jun 21 12:38:31.562: //39/000000000000/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
001941: Jun 21 12:38:31.562: //39/000000000000/SIP/Info/ccsip_offer_ans_delete:
001942: Jun 21 12:38:31.562: //39/000000000000/SIP/Info/ccsip_iwf_delete: 
001943: Jun 21 12:38:31.562: //39/000000000000/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A797E8
001944: Jun 21 12:38:31.562: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetContextFromTable: NO context for key[35]
001945: Jun 21 12:38:31.974: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A797E8) with key=[36] to table
001946: Jun 21 12:38:31.974: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
001947: Jun 21 12:38:31.974: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
001948: Jun 21 12:38:31.974: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
001949: Jun 21 12:38:31.974: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
001950: Jun 21 12:38:31.974: //40/000000000000/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
001951: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_call_setup_request: Set Protocol information
001952: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_iwf_handle_peer_event:
001953: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 1, Event Id: 176
001954: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_iwf_process_event: 
001955: Jun 21 12:38:31.974: //40/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SET_MODE
001956: Jun 21 12:38:31.974: //40/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
001957: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_get_int_type_frm_set_mode_ev:
001958: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/is_mode_sip_sip_md:
001959: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_get_int_type_frm_set_mode_ev:
001960: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/is_mode_sip_sip_ed:
001961: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_get_int_type_frm_set_mode_ev:
001962: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/is_mode_sip_h32x_in_set_mode:
001963: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_get_int_type_frm_set_mode_ev:
001964: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/is_mode_sip_h323_in_set_mode:
001965: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_get_int_type_frm_set_mode_ev:
001966: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/is_mode_sip_sccp_in_set_mode:
001967: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_get_int_type_frm_set_mode_ev:
001968: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/is_mode_sip_sccp_in_set_mode:
001969: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/sip_iwf_def_set_mode_hdlr: Setting SPI mode to SIP-TDM
001970: Jun 21 12:38:31.974: //40/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_sccp_early_dialog_container
001971: Jun 21 12:38:31.974: //40/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:CNFSM_NO_STATE_CHANGE
001972: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_iwf_handle_peer_event: Return value : SIP_IWF_SUCCESS
001973: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_iwf_handle_peer_event:
001974: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_iwf_map_ccapi_event_to_iwf_event: Event Category: 3, Event Id: 5
001975: Jun 21 12:38:31.974: //40/000000000000/SIP/Info/ccsip_iwf_process_event: 
001976: Jun 21 12:38:31.974: //40/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SET_FLOW_MODE
001977: Jun 21 12:38:31.978: //40/000000000000/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
001978: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/is_fa2ft_md_flow_mode_transition:
001979: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/is_fa2ft_flow_mode_transition:
001980: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/ccsip_get_flow_mode_frm_set_flow_mode_ev:
001981: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/is_fa2ft_flow_mode_transition:
001982: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/ccsip_get_flow_mode_frm_set_flow_mode_ev:
001983: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2
001984: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/ccsip_iwf_handle_peer_event: Return value : SIP_IWF_SUCCESS
001985: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/ccsip_call_setup_request: Before processing SETUP REQccb->pld.flags_ipip = 200
001986: Jun 21 12:38:31.978: //40/000000000000/SIP/Info/ccsip_call_setup_request: After processing SETUP REQccb->pld.flags_ipip = 200
001987: Jun 21 12:38:31.978: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: target_host : p03.neotel.at target_port : 5060
001988: Jun 21 12:38:31.978: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIGetOutboundHostAndDestHostPrivate: CCSIP: outbound_host : p03.neotel.at outbound_port : 5060
001989: Jun 21 12:38:31.978: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_CALL_SETUP
001990: Jun 21 12:38:31.978: //40/87C9E1868034/SIP/Info/ccsip_call_setup_request: Incrementing call counter to [1] in dial-peer [1001]
001991: Jun 21 12:38:31.978: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 2
001992: Jun 21 12:38:31.978: //40/87C9E1868034/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 28 to table
001993: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIGetCallConfig: preferred_codec set[0] type :No Codec    bytes: 0
001994: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIGetCallConfig: Media forking disabled
001995: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
001996: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPICanSetFallbackFlag: Local Fallback is not active
001997: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
001998: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
001999: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
002000: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE
002001: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
002002: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=38
002003: Jun 21 12:38:31.982: //40/87C9E1868034/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
002004: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIGetCallConfig: Media forking disabled
002005: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
002006: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
002007: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
002008: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
002009: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/preprocessSetup:
 This is a not a SIGO Call -, could be DM call
002010: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/ccsip_iwf_process_event: 
002011: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_INIT_CALL_SETUP
002012: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
002013: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/ccsip_iwf_process_event: IWF - cnfsm ret 2
002014: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sip_gw_pre_setup_add_sdp_container: DNS/ENUM resolution required; Deferred Creating SDP
002015: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIValidateGtd: Signal Forward disabled
002016: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIValidateTunnelData: RawMsg/QSIG Tunneling Not Enabled
002017: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIAddMLPPServicesInfo: No MLP Info available on incoming leg
002018: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIPreprocessUriFormat: Url cfg for 1: 2,phone-ctxt=FALSE
002019: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIAddCiscoGcid: Gcid value not set - not adding header.
002020: Jun 21 12:38:31.982: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddPrivacyandIdentityInfo: ccb->local_host_name,ccb->src_addr_str is NULL
002021: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info CLI not enabled
002022: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Error/sipSPI_ipip_set_history_info_header: ccb->src_addr_str is NULL
002023: Jun 21 12:38:31.982: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_DNS_RESOLVE
002024: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_SENT_DNS)
002025: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS)  to (STATE_IDLE, SUBSTATE_SENT_DNS)
002026: Jun 21 12:38:31.982: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002027: Jun 21 12:38:31.982: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
002028: Jun 21 12:38:31.982: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
002029: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIUaddCcbToUACTable: ****Adding to UAC table.
002030: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A797E8 key=8C73283B-934711E9-803AFC79-894ABFDB@bvoip.at
002031: Jun 21 12:38:31.982: //40/87C9E1868034/SIP/Info/sipSPIUsetBillingProfile: sipCallId for billing records = 8C73283B-934711E9-803AFC79-894ABFDB@bvoip.at
002032: Jun 21 12:38:31.986: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: TYPE SRV query for _sip._udp.p03.neotel.at and type:1
002033: Jun 21 12:38:31.986: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Server Name p03.neotel.at
002034: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Priority 0 Weight 5 Port 5060
002035: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Calculating Random Number : 53076 factor 13107 value 4
002036: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: Selected Server is p03.neotel.at
002037: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: TYPE A query successful for p03.neotel.at
002038: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_a_query: ttl for A records = 199 seconds
002039: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: IP Address of p03.neotel.at is:
002040: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: 193.84.65.82
002041: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sip_dns_type_srv_query: ttl for SRV records = 199 seconds
002042: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 43
002043: Jun 21 12:38:31.990: //40/87C9E1868034/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_IDLE, SUBSTATE_SENT_DNS)  to (STATE_IDLE, SUBSTATE_NONE)
002044: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: sipSPICacheHostToCCB dnsResponse.num_hosts = 1
002045: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/sipSPICacheHostToCCB: IP Address No. 1, IP address 193.84.65.82
002046: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002047: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
002048: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
002049: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002050: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
002051: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
002052: Jun 21 12:38:31.990: //40/87C9E1868034/SIP/Info/sipSPIRscmsmAvail: Value returned by check is = 0
002053: Jun 21 12:38:31.990: //40/87C9E1868034/SIP/Info/sipSPICompareHistoryInfoWithMatchedDialpeer: call-route history-info CLI not enabled
002054: Jun 21 12:38:31.990: //40/87C9E1868034/SIP/Info/sipSPI_ipip_set_history_info_header: No HI header recvd from container
002055: Jun 21 12:38:31.990: //40/87C9E1868034/SIP/Info/sipSPIAddPrivacyandIdentityInfo: Removing "id" value from Privacy
002056: Jun 21 12:38:31.990: //40/87C9E1868034/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
002057: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002058: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
002059: Jun 21 12:38:31.990: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.200.207.19
002060: Jun 21 12:38:31.990: //40/87C9E1868034/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
002061: Jun 21 12:38:31.994: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002062: Jun 21 12:38:31.994: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
002063: Jun 21 12:38:31.994: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
002064: Jun 21 12:38:31.994: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 18114 for stream 1
002065: Jun 21 12:38:31.994: //-1/xxxxxxxxxxxx/SIP/Info/convert_codec_bytes_to_ptime: Values :Codec: g711alaw codecbytes :160, ptime: 20
002066: Jun 21 12:38:31.994: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetMediaDirectionForStream: Setting Media direction SENDRECV for stream 1
002067: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/sip_generate_sdp_xcaps_list: Modem Relay and T38 disabled. X-cap not needed
002068: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/sipSPIOutgoingCallSDP: Creating recv-only stream for outbound call
002069: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Media/sipSPIProcessRtpSessions: No active streams.
002070: Jun 21 12:38:31.994: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
002071: Jun 21 12:38:31.994: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
002072: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Event/Session-Timer/sipSTSLMain: Event: E_STSL_SESSION_REFRESH_REQ
002073: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Event/Session-Timer/sipSTSLMain: dir:1, method:102, resp_code:0, container:8986AE6C
002074: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/Session-Timer/sipSTSLSRReqSend: Session timer is not required
002075: Jun 21 12:38:31.994: //40/87C9E1868034/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
002076: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/ccsip_offer_ans_handle_sent_sdp:
002077: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/ccsip_offer_ans_process_event:
002078: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/State/ccsip_cnfsm_debugs: OA:cur_container:ccsip_offer_ans_main_container, cur_state:S_SIP_EARLY_DIALOG_IDLE, event:E_SIP_INVITE_SDP_SENT
002079: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/ccsip_offer_ans_is_invite_offer_valid:  - 1
002080: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/ccsip_offer_ans_common_offer_sent_hdlr:
002081: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/ccsip_iwf_handle_network_event:
002082: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/ccsip_iwf_process_event: 
002083: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_sccp_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_SENT_SDP
002084: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/is_sent_sccp_do_video_inactive:
002085: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/is_mode_sip_sccp_do_video:
002086: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/is_mode_sip_sccp_do_video:
002087: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/Info/sip_iwf_def_ed_sent_sdp_offer_hdlr:
002088: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/State/ccsip_cnfsm_debugs: IWF:next_state:S_SIP_IWF_SDP_SENT_AWAIT_SDP
002089: Jun 21 12:38:31.994: //40/87C9E1868034/SIP/State/ccsip_cnfsm_debugs: OA:next_state:S_SIP_EARLY_DIALOG_OFFER_SENT
002090: Jun 21 12:38:31.998: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIgetRegistrarHost: registrar host retrieved : bvoip.at
SIP: (40) Group (a= group line) attribute, level 65535 instance 1 not found.
002091: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Info/sipSPIGetCallExtensionSupported: anat enabled, src_sdp dont have anat
002092: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Info/sipSPISendInvite: Associated container=0x8986AE6C to Invite
002093: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Transport/sipSPISendInvite: Sending Invite to the transport layer
002094: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Transport/sipSPIGetSwitchTransportFlag: Return the Dial peer configuration, Switch Transport is FALSE
002095: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Transport/sipSPITransportSendMessage: msg=0x8AEB8CA0, addr=193.84.65.82, port=5060, sentBy_port=0, local_addr=, is_req=1, transport=1, switch=0, callBack=0x814AC1B0
002096: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
002097: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
002098: Jun 21 12:38:31.998: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
002099: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Transport/sipTransportLogicSendMsg: Set to send the msg=0x8AEB8CA0
002100: Jun 21 12:38:31.998: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x8AEB8CA0, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
002101: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Info/sentInviteRequest: Sent Invite in state STATE_IDLE
002102: Jun 21 12:38:31.998: //-1/xxxxxxxxxxxx/SIP/Info/sentInviteRequest: Transaction active. Facilities will be queued.
002103: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/State/sipSPIChangeState: 0x88A797E8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (STATE_SENT_INVITE, SUBSTATE_NONE)
002104: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Media/sipSPIAddStream: Adding stream 1 of type voice+dtmf (callid 40) to the VOIP RTP library
002105: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
002106: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Info/resolve_media_ip_address_to_bind: Media already bound, use existing source_media_ip_addr
002107: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
002108: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Media/sipSPIUpdateRtcpSession: sipSPIUpdateRtcpSession for m-line 1
002109: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Media/sipSPIUpdateRtcpSession: rtcp_session info
laddr = 10.200.207.19, lport = 18114, raddr = 0.0.0.0, rport=0, do_rtcp=FALSE
src_callid = 40, dest_callid = -1, stream type = voice+dtmf, stream direction = RECVONLY
media_ip_addr =  - , vrf tableid = 0 media_addr_type = 1
002110: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Media/sipSPIUpdateRtcpSession: No rtp session, creating a new one
002111: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Info/sipSPICreateRtpSession: sess: 8686349C do_rtcp:0
002112: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Media/sipSPICreateRtpSession: stun is disabled
002113: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/State/sipSPIChangeStreamState: Stream (callid =  40)  State changed from (STREAM_ADDING) to (STREAM_ACTIVE)
002114: Jun 21 12:38:31.998: //40/87C9E1868034/SIP/Info/sipSPIUpdateCallEntry:
Call 40 set InfoType to SPEECH
002115: Jun 21 12:38:32.002: //40/87C9E1868034/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:06801234567@p03.neotel.at:5060 SIP/2.0
Via: SIP/2.0/UDP 10.200.207.19:5060;branch=z9hG4bKC211F
From: "Gernot Mustermann" <sip:072012345612@bvoip.at>;tag=6F80C-F14
To: <sip:06801234567@p03.neotel.at>
Date: Fri, 21 Jun 2019 10:38:31 GMT
Call-ID: 8C73283B-934711E9-803AFC79-894ABFDB@bvoip.at
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE:  1800
Cisco-Guid: 2278154630-2470908393-2150956153-2303377371
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Max-Forwards: 70
Timestamp: 1561113511
Contact: <sip:072012345612@10.200.207.19:5060>
Expires: 180
Allow-Events: telephone-event
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 243
 
v=0
o=CiscoSystemsSIP-GW-UserAgent 3120 6158 IN IP4 10.200.207.19
s=SIP Call
c=IN IP4 10.200.207.19
t=0 0
m=audio 18114 RTP/AVP 8 100
c=IN IP4 10.200.207.19
a=rtpmap:8 PCMA/8000
a=rtpmap:100 X-NSE/8000
a=fmtp:100 192-194
a=ptime:20
ACK sip:06801234567@p03.neotel.at:5060 SIP/2.0
Via: SIP/2.0/UDP 10.200.207.19:5060;branch=z9hG4bKC211F
From: "Gernot Mustermann" <sip:072012345612@bvoip.at>;tag=6F80C-F14
To: <sip:06801234567@p03.neotel.at>;tag=FlrvuPw918
Date: Fri, 21 Jun 2019 10:38:31 GMT
Call-ID: 8C73283B-934711E9-803AFC79-894ABFDB@bvoip.at
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event
Content-Length: 0
 

002176: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 24
002177: Jun 21 12:38:33.519: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[33] removed.
002178: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
002179: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A73DF8 key=b2fad331-56f58a74-84e25a6@193.84.65.820720123456
002180: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
002181: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
002182: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
002183: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/ccsip_offer_ans_delete:
002184: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/ccsip_iwf_delete: 
002185: Jun 21 12:38:33.519: //36/7A49F1EC8032/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A73DF8
002186: Jun 21 12:38:41.527: //-1/xxxxxxxxxxxx/SIP/Info/HandleUdpIPv4SocketReads: Msg enqueued for SPI with IP addr: [193.84.65.82]:5060, local_address:[ - ]
002187: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 2 for event 1
002188: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportProcessNWNewConnMsg: context=0x88181B48
002189: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerProcessNewConnMsg: gConnTab=0x88181B48, addr=193.84.65.82, port=5060, local_addr=, connid=2, transport=UDP
002190: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
OPTIONS sip:0720123456@10.200.207.19:5060 SIP/2.0
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK3819053
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-d71e1641
To: sip:0720123456@10.200.207.19:5060
Call-ID: b2fad331-bbf58a74-07e25a6@193.84.65.82
CSeq: 1 OPTIONS
Content-Length: 0
 

002191: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_new_msg_preprocessor: Checking Invite Dialog
002192: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIAddContextToTable: Added context(0x88A73DF8) with key=[37] to table
002193: Jun 21 12:38:41.531: //-1/000000000000/SIP/Info/ccsip_offer_ans_init:
002194: Jun 21 12:38:41.531: //-1/000000000000/SIP/Info/ccsip_iwf_init: 
002195: Jun 21 12:38:41.531: //-1/000000000000/SIP/Info/ccsip_ipip_media_service_init:
002196: Jun 21 12:38:41.531: //-1/000000000000/SIP/Info/sipSPI_ipip_vcc_Initialization:  Entry...
002197: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Dialog Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
002198: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002199: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
002200: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
002201: Jun 21 12:38:41.531: //-1/92241FC3803B/SIP/State/sipSPIChangeState: 0x88A73DF8 : State change from (STATE_NONE, SUBSTATE_NONE)  to (STATE_IDLE, SUBSTATE_NONE)
002202: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
002203: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Info/sipSPISetDateHeader: Converting TimeZone CET to SIP default timezone = GMT
002204: Jun 21 12:38:41.531: //-1/xxxxxxxxxxxx/SIP/Transport/sipSPIUpdateResponseInfo: Subsq Transaction Address 193.84.65.82,Port 5060, Transport 1, SentBy Port 5060
002205: Jun 21 12:38:41.531: //41/92241FC3803B/SIP/Info/ccsipInitPldCallingInfo: non-numeric calling number: hello
002206: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetViaHostInURLFormat: VIA URL:sip:193.84.65.82:5060, Host:193.84.65.82
002207: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetShrlPeer: Try match incoming dialpeer for Calling number: : hello
002208: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetFromCalledPartyId: P-Called-Party-ID header not found
002209: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetPeerByCalledPartyId: P-Called-Party-ID not found or parse error
002210: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetCallConfig: No match found for P-Called-Party-ID
002211: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetCallConfig: Peer tag 1000 matched for incoming call
002212: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
002213: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
002214: Jun 21 12:38:41.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002215: Jun 21 12:38:41.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
002216: Jun 21 12:38:41.535: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
002217: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPICheckReliableProvStringtag: Unable to access supported header values
002218: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetCallConfig: Precondition tag absent in Require/Supported header
002219: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetCallConfig: Media Antitrombone disabled
002220: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPISetMediaFlowMode: Storing the configured mode as FLOW-THROUGH
002221: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPISetMediaFlowMode: xcoder high-density disabled
002222: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPISetMediaFlowMode: Flow Mode set to FLOW_THROUGH
002223: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetCallConfig: Using Voice Class Codec, tag = 1 and offer-all is = FALSE
002224: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Media/sipSPICopyStunConfigFromPeerToCCB: Firewall traversal is not enabled
002225: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetModemInfoPerCall: peer_callID=0
002226: Jun 21 12:38:41.535: //41/92241FC3803B/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
002227: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPIGetCallConfig: Media forking disabled
002228: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
002229: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
002230: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
002231: Jun 21 12:38:41.535: //41/92241FC3803B/SIP/Info/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
002232: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Info/sipSPIValidateStreamAddrType: stream:1, Mode : 1
002233: Jun 21 12:38:41.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002234: Jun 21 12:38:41.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: calling ip_best_local_address()
002235: Jun 21 12:38:41.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_media_ip_address_to_bind: return addr 10.200.207.19
002236: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = 10.200.207.19
002237: Jun 21 12:38:41.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling reg_invoke_ip_first_hop()
002238: Jun 21 12:38:41.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: calling ip_best_local_address()
002239: Jun 21 12:38:41.539: //-1/xxxxxxxxxxxx/SIP/Info/resolve_sig_ip_address_to_bind: return addr 10.200.207.19
002240: Jun 21 12:38:41.539: //-1/xxxxxxxxxxxx/SIP/Event/sipSPIEventInfo: Queued event from SIP SPI : SIPSPI_EV_CC_OPTIONS_RESP
002241: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Info/sact_idle_new_message_options: ccsip_api_options_ind returned: SIP_SUCCESS
002242: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/State/sipSPIChangeState: 0x88A73DF8 : State change from (STATE_IDLE, SUBSTATE_NONE)  to (SIP_STATE_OPTIONS_WAIT, SUBSTATE_NONE)
002243: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Info/sipSPIUaddCcbToUASReqTable: ****Adding to UAS Request table.
002244: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Info/sipSPIUaddCcbToTable: Added to table. ccb=0x88A73DF8 key=b2fad331-bbf58a74-07e25a6@193.84.65.820720123456
002245: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Info/sipSPIUaddccCallIdToTable: Adding call id 29 to table
002246: Jun 21 12:38:41.539: //-1/xxxxxxxxxxxx/SIP/Info/ccsip_process_sipspi_queue_event: ccsip_spi_get_msg_type returned: 3 for event 38
002247: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Info/sipSPISendOptionsResponse: Associated container=0x8986B5FC to Options Response
002248: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Transport/sipSPITransportSendMessage: msg=0x898976EC, addr=193.84.65.82, port=5060, sentBy_port=5060, local_addr=, is_req=0, transport=1, switch=0, callBack=0x814B105C
002249: Jun 21 12:38:41.539: //41/92241FC3803B/SIP/Transport/sipSPITransportSendMessage: Proceedable for sending msg immediately
002250: Jun 21 12:38:41.543: //41/92241FC3803B/SIP/Transport/sipTransportLogicSendMsg: switch transport is 0
002251: Jun 21 12:38:41.543: //41/92241FC3803B/SIP/Transport/sipTransportLogicSendMsg: Trying to send resp=0x898976EC to default port=5060
002252: Jun 21 12:38:41.543: //-1/xxxxxxxxxxxx/SIP/Transport/sipConnectionManagerGetConnection: connection required for raddr:193.84.65.82, rport:5060 with laddr:
002253: Jun 21 12:38:41.543: //41/92241FC3803B/SIP/Transport/sipTransportLogicSendMsg: Connection obtained...sending msg=0x898976EC
002254: Jun 21 12:38:41.543: //-1/xxxxxxxxxxxx/SIP/Transport/sipTransportPostSendMessage: Posting send for msg=0x898976EC, addr=193.84.65.82, port=5060, local_addr=, connId=2 for UDP
002255: Jun 21 12:38:41.551: //41/92241FC3803B/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 193.84.65.82:5060;branch=z9hG4bK3819053
From: sip:hello@nat.refresh.local;tag=uloc-52-5d083410-f84-35163-79a18361-d71e1641
To: sip:0720123456@10.200.207.19:5060;tag=71D48-223E
Date: Fri, 21 Jun 2019 10:38:41 GMT
Call-ID: b2fad331-bbf58a74-07e25a6@193.84.65.82
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 1 OPTIONS
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Accept: application/sdp
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Content-Type: application/sdp
Content-Length: 456
 
v=0
o=CiscoSystemsSIP-GW-UserAgent 9540 8979 IN IP4 10.200.207.19
s=SIP Call
c=IN IP4 10.200.207.19
t=0 0
m=audio 0 RTP/AVP 18 0 8 9 4 2 15 3
c=IN IP4 10.200.207.19
m=image 0 udptl t38
c=IN IP4 10.200.207.19
a=T38FaxVersion:0
a=T38MaxBitRate:9600
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:320
a=T38FaxUdpEC:t38UDPRedundancy

002256: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/sipSPIUdeleteccCallIdFromTable: Removing call id 25
002257: Jun 21 12:38:53.531: //-1/xxxxxxxxxxxx/SIP/Info/sipSPIDeleteContextFromTable: Context for key=[34] removed.
002258: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/sipSPIUdeleteCcbFromUASReqTable: ****Deleting from UAS Request table.
002259: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/sipSPIUdeleteCcbFromTable: Deleting from table. ccb=0x88A68A18 key=b2fad331-09f58a74-c5e25a6@193.84.65.820720123456
002260: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/sipSPIUdeleteCcbFromUASRespTable: ****Deleting from UAS Response table.
002261: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/sipSPIFlushEventBufferQueue: There are 0 events on the internal queue that are going to be free'd
002262: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/sipSPI_ipip_free_codec_profile: Codec Profiles Freed
002263: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/ccsip_offer_ans_delete:
002264: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/ccsip_iwf_delete: 
002265: Jun 21 12:38:53.531: //37/863708D78033/SIP/Info/sipSPIUfreeOneCCB: Freeing ccb 88A68A18
UC520#no debug all
All possible debugging has been turned off
UC520#terminal no monitor
UC520#
UC520#
UC520#
UC520#exit
0 Helpful
Customers Also Viewed These Support Documents