Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for
- Cisco Community
- :
- About bernarddmurphy
Stats
Member since
04-26-2012
7
Posts
0
Helpful
0
Solutions
Created by
bernarddmurphy
in IP Telephony and Phones
in IP Telephony and Phones
12-15-2012
08:18 AM
12-15-2012
08:18 AM
thanks num-exp works great !
... View more
Created by
bernarddmurphy
in IP Telephony and Phones
in IP Telephony and Phones
12-15-2012
07:45 AM
12-15-2012
07:45 AM
Hi Chris, It's just the voice gateway. no communication manager or any other cisco products involved. Normally inbound calls from PSTN to the gateway are directed to a SIP PBX, but I need one destination number to just go straight back out to another PSTN number. hope you can help thanks
... View more
Created by
bernarddmurphy
in IP Telephony and Phones
in IP Telephony and Phones
12-15-2012
07:10 AM
12-15-2012
07:10 AM
I am struggling with something that sounds like it ought to be simple. I have a 2901 UC voice gateway and need to redirect one of the inbound DDI numbers to an external destination. i.e. when you ring inbound from the PSTN to the number 123456 it should direct straight out to another PSTN number 654321 etc. How should I achieve this, does it use translation rules or dial-peers or something else ? Thanks
... View more
Labels:
04-29-2012
06:20 AM
You can close this question, the cisco was not at fault and the SIP PBX was not setting the first marker bit to TRUE on the first RF2833 event. Problem solved.
... View more
04-28-2012
10:28 AM
Ok, here is the whole thing. The DTMF digit sent was '1' and was tried twice, both unsuccessful. term mon s-vgw01-hkg# Apr 28 17:23:37.527: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: INVITE sip:28881010@10.50.47.19 SIP/2.0 Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bKytr0D0yj4D35K Max-Forwards: 69 From: "Nick" ;tag=vr6UyBBp8gU0p To: Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec CSeq: 27480844 INVITE Contact: User-Agent: Configured by 2600hz! Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: precondition, path, replaces Allow-Events: talk, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 242 X-FS-Support: update_display Remote-Party-ID: "Nick" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1335616451 1335616452 IN IP4 10.50.47.30 s=FreeSWITCH c=IN IP4 10.50.47.30 t=0 0 m=audio 17366 RTP/AVP 0 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 Apr 28 17:23:37.531: //-1/B98777B3B479/CCAPI/cc_api_display_ie_subfields: cc_api_call_setup_ind_common: cisco-username=35576500 ----- ccCallInfo IE subfields ----- cisco-ani=35576500 cisco-anitype=0 cisco-aniplan=0 cisco-anipi=0 cisco-anisi=1 dest=28881010 cisco-desttype=0 cisco-destplan=0 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=0 cisco-rdnplan=0 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Apr 28 17:23:37.531: //-1/B98777B3B479/CCAPI/cc_api_call_setup_ind_common: Interface=0x2B460AA4, Call Info( Calling Number=35576500,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed), Called Number=28881010(TON=Unknown, NPI=Unknown), Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Incoming Dial-peer=3, Progress Indication=NULL(0), Calling IE Present=TRUE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=4584 Apr 28 17:23:37.531: //-1/B98777B3B479/CCAPI/ccCheckClipClir: In: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed) Apr 28 17:23:37.531: //-1/B98777B3B479/CCAPI/ccCheckClipClir: Out: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed) Apr 28 17:23:37.531: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 17:23:37.531: :cc_get_feature_vsa malloc success Apr 28 17:23:37.531: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 17:23:37.531: cc_get_feature_vsa count is 1 Apr 28 17:23:37.531: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 17:23:37.531: :FEATURE_VSA attributes are: feature_name:0,feature_time:737578624,feature_id:4580 Apr 28 17:23:37.531: //4584/B98777B3B479/CCAPI/cc_api_call_setup_ind_common: Set Up Event Sent; Call Info(Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed), Called Number=28881010(TON=Unknown, NPI=Unknown)) Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/cc_process_call_setup_ind: Event=0x3150F328 Apr 28 17:23:37.535: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search: Try with the demoted called number 28881010 Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccCallSetContext: Context=0x2BFFF5C0 Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/cc_process_call_setup_ind: >>>>CCAPI handed cid 4584 with tag 3 to app "_ManagedAppProcess_Default" Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccCallProceeding: Progress Indication=NULL(0) Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccCallSetupRequest: Destination=, Calling IE Present=TRUE, Mode=0, Outgoing Dial-peer=7, Params=0x2BFFCDE0, Progress Indication=NULL(0) Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccCheckClipClir: In: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed) Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccCheckClipClir: Out: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed) Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccCallSetupRequest: Destination Pattern=[1-9]......., Called Number=28881010, Digit Strip=TRUE Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccCallSetupRequest: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed), Called Number=28881010(TON=Unknown, NPI=Unknown), Redirect Number=, Display Info=Nick Account Number=35576500, Final Destination Flag=TRUE, Guid=B98777B3-908D-11E1-B479-891BB6D70534, Outgoing Dial-peer=7 Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/cc_api_display_ie_subfields: ccCallSetupRequest: cisco-username=35576500 ----- ccCallInfo IE subfields ----- cisco-ani=35576500 cisco-anitype=0 cisco-aniplan=0 cisco-anipi=0 cisco-anisi=1 dest=28881010 cisco-desttype=0 cisco-destplan=0 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=0 cisco-rdnplan=0 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccIFCallSetupRequestPrivate: Interface=0x2BC79A0C, Interface Type=6, Destination=, Mode=0x0, Call Params(Calling Number=35576500,(Calling Name=Nick)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed), Called Number=28881010(TON=Unknown, NPI=Unknown), Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=7, Call Count On=FALSE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=) Apr 28 17:23:37.535: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 17:23:37.535: :cc_get_feature_vsa malloc success Apr 28 17:23:37.535: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 17:23:37.535: cc_get_feature_vsa count is 2 Apr 28 17:23:37.535: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 17:23:37.535: :FEATURE_VSA attributes are: feature_name:0,feature_time:737579296,feature_id:4581 Apr 28 17:23:37.535: //4585/B98777B3B479/CCAPI/ccIFCallSetupRequestPrivate: SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1 Apr 28 17:23:37.535: //4585/B98777B3B479/CCAPI/ccCallSetContext: Context=0x2BFFCD90 Apr 28 17:23:37.535: //4584/B98777B3B479/CCAPI/ccSaveDialpeerTag: Outgoing Dial-peer=7 Apr 28 17:23:37.539: //-1/xxxxxxxxxxxx/HPI/[]/hpi_dspmgr_open: Apr 28 17:23:37.539: hpi [] DSP [0/0x0] S_HPI_CLOSED(0) E_HPI_DSPRM_OPEN/SET_CODEC(59) Apr 28 17:23:37.539: HPI/[]/hpi_dspmgr_open: tdm_info=0x0, tsp_info=0x0, dsp_sdb=0x314DE180 call_id=4585, dsprm_type=32 Apr 28 17:23:37.539: hpi [] DSP [0/0x0] -> S_HPI_CLOSED(0) Apr 28 17:23:37.539: //4585/B98777B3B479/HPI/[]/hpi_dspmgr_open: Allocated DSP resource: ; dsp_intf=0x3196F010 hpi_cdb=0x2BFA4554 ret=1 Apr 28 17:23:37.539: //4585/B98777B3B479/HPI/[]/hpi_dspmgr_open: exit@22793 Apr 28 17:23:37.539: //4584/B98777B3B479/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bKytr0D0yj4D35K From: "Nick" ;tag=vr6UyBBp8gU0p To: Date: Sat, 28 Apr 2012 17:23:37 GMT Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec CSeq: 27480844 INVITE Allow-Events: telephone-event Server: Cisco-SIPGateway/IOS-15.2(1)T1, Content-Length: 0 Apr 28 17:23:37.807: //4585/B98777B3B479/CCAPI/cc_api_call_proceeding: Interface=0x2BC79A0C, Progress Indication=INBAND(8) Apr 28 17:23:37.807: //4584/B98777B3B479/CCAPI/ccCallCutProgress: Progress Indication=INBAND(8), Signal Indication=INTERCEPT(2), Cause Value=0 Voice Call Send Alert=FALSE, Call Entry(Alert Sent=FALSE) Apr 28 17:23:37.807: //4584/B98777B3B479/CCAPI/ccCallCutProgress: Call Entry(Responsed=TRUE) Apr 28 17:23:37.807: //4584/B98777B3B479/CCAPI/ccConferenceCreate: (confID=0x3126EF58, callID1=0x11E8, gcid=B98813DB-908D11E1-B47C891B-B6D70534, tag=0x0) Apr 28 17:23:37.807: //4585/B98777B3B479/CCAPI/ccConferenceCreate: (confID=0x3126EF58, callID2=0x11E9, gcid=B98813DB-908D11E1-B47C891B-B6D70534, tag=0x0) Apr 28 17:23:37.807: //4584/B98777B3B479/CCAPI/ccConferenceCreate: Conference Id=0x3126EF58, Call Id1=4584, Call Id2=4585, Tag=0x0 Apr 28 17:23:37.811: //4584/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream: Apr 28 17:23:37.811: cc_api_get_xcode_stream : 4803 Apr 28 17:23:37.811: //4584/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream: Apr 28 17:23:37.811: cc_api_get_xcode_stream : 4803 Apr 28 17:23:37.811: //4584/B98777B3B479/CCAPI/cc_api_bridge_done: Conference Id=0x85B, Source Interface=0x2B460AA4, Source Call Id=4584, Destination Call Id=4585, Disposition=0x0, Tag=0x0 Apr 28 17:23:37.811: //4585/B98777B3B479/CCAPI/cc_api_bridge_done: Conference Id=0x85B, Source Interface=0x2BC79A0C, Source Call Id=4585, Destination Call Id=4584, Disposition=0x0, Tag=0xFFFFFFFF Apr 28 17:23:37.811: //4584/B98777B3B479/CCAPI/cc_generic_bridge_done: Conference Id=0x85B, Source Interface=0x2BC79A0C, Source Call Id=4585, Destination Call Id=4584, Disposition=0x0, Tag=0xFFFFFFFF Apr 28 17:23:37.811: //4584/B98777B3B479/CCAPI/ccConferenceCreate: Call Entry(Conference Id=0x85B, Destination Call Id=4585) Apr 28 17:23:37.811: //4585/B98777B3B479/CCAPI/ccConferenceCreate: Call Entry(Conference Id=0x85B, Destination Call Id=4584) Apr 28 17:23:37.811: //4585/B98777B3B479/CCAPI/cc_api_caps_ind: Destination Interface=0x2B460AA4, Destination Call Id=4584, Source Call Id=4585, Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1, Modem=0x2, Codec Bytes=20, Signal Type=3) Apr 28 17:23:37.811: //4585/B98777B3B479/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=1000(ms), Fax Nom=300(ms)) Apr 28 17:23:37.811: //4584/B98777B3B479/CCAPI/cc_api_caps_ind: Destination Interface=0x2BC79A0C, Destination Call Id=4585, Source Call Id=4584, Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1, Modem=0x0, Codec Bytes=80, Signal Type=2) Apr 28 17:23:37.811: //4584/B98777B3B479/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=1000(ms), Fax Nom=300(ms)) Apr 28 17:23:37.811: //4584/B98777B3B479/CCAPI/cc_api_caps_ack: Destination Interface=0x2BC79A0C, Destination Call Id=4585, Source Call Id=4584, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=80, Signal Type=2, Seq Num Start=6071) Apr 28 17:23:37.811: //4585/B98777B3B479/CCAPI/cc_api_caps_ack: Destination Interface=0x2B460AA4, Destination Call Id=4584, Source Call Id=4585, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=80, Signal Type=2, Seq Num Start=6071) Apr 28 17:23:37.811: //4584/B98777B3B479/CCAPI/ccCallNotify: Data Bitmask=0x7, Call Id=4584 Apr 28 17:23:37.811: //4584/B98777B3B479/CCAPI/cc_process_notify_bridge_done: Conference Id=0x85B, Call Id1=4584, Call Id2=4585 Apr 28 17:23:37.811: //4585/B98777B3B479/HPI/[0/1:1]/hpi_init: Apr 28 17:23:37.811: //4585/B98777B3B479/HPI/[0/1:1]/hpi_init: Open channel Packet details: Packet Length=16, Channel Id=1, Packet Id=74 ALawULawSelect=A Law, Associated SignalingChannel=150 Timeslot=0, SerialPort=0 Apr 28 17:23:37.811: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.811: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_CLOSED(0) E_HPI_DSP_OPEN_VOICE_CHANNEL(11) Apr 28 17:23:37.811: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.811: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_IDLE(1) Apr 28 17:23:37.811: //4585/B98777B3B479/HPI/[0/1:1]/hpi_open_service: Apr 28 17:23:37.811: //4585/B98777B3B479/HPI/[0/1:1]/hpi_open_service: Setting codec g711ulaw Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_set_codec: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_IDLE(1) E_HPI_DSPRM_OPEN/SET_CODEC(59) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_dsprm_callback: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_IDLE(1) Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_IDLE(1) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_voice_config_params: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_encap_config: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_encap_config: RTP information Packet details: Packet Length=44, Channel Id=1, Packet Id=92 TransportProtocol=2 Tx SSRC=0x0A63, Rx SSRC=0x00, Tx VPXCC=0x80, Rx VPXCC=0x0 SID support=0, TSE payload=101, Sequence number start=0x17B7, Redundancy=0 ClearChannel payload type=125, Fax payload type=122, ALaw PCM switchover=8 MuLaw PCM switchover=0, DTMF payload type=121, NTE receive payload type=101, sprt payloadtype=0 Lmr tone payload type=0, NTE tone payload type=0 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_IDLE(1) E_HPI_DSP_ENC_CONFIG(29) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_IDLE(1) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_set_playout_config: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_set_playout_config: Packet details: Packet Length=18, Channel Id=1, Packet Id=76 Mode=1, Initial=60(ms), Min=40(ms), Max=1000(ms), fax_nom=300(ms) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_IDLE(1) E_HPI_DSP_SET_VOICE_PLAYOUT_DELAY(13) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_IDLE(1) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_info_field_size_config: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_info_field_size_config: Info field size=80 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_modem_relay_protocol_config: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_idle_code_det: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_idle_code_det: Packet details: Packet Length=14, Channel Id=1, Packet Id=116 Enable=FALSE, Code=0x00000000, Duration=6000(ms) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_IDLE(1) E_HPI_DSP_IDLE_CODE_CONTROL (51) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_IDLE(1) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_echo_cancel: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_echo_cancel: Packet details: Packet Length=22, Channel Id=1, Packet Id=66 Flags=0x00000F00, NLP Threshold=-21(dB), Suppressor Coverage=7(s), Attenuation=2(s), fx_mode=0 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_IDLE(1) E_HPI_DSP_ECHO_CANCELLER_CONTROL(3) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_IDLE(1) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_cng_config: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_start_service: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_voice_mode: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_voice_mode: Packet details: Packet Length=34, Channel Id=1, Packet Id=73 CodingType=1, Voice field size=80(bytes), VAD Flag=0, Echo Length=128(ms), ComfortNoise=enable, Inband detect=0x00000001, DigitRelay=0, AGC Flag=0, ECAN TestGroup=0, ECAN TestNumber=0, DynamicPayload=0, ANS Tone Treatment=0 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_IDLE(1) E_HPI_DSP_VOICE_MODE(10) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_start_service: exit@4348 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_call_progress_detect: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_call_progress_detect: exit@7502 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_voice_config_params: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_echo_cancel: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_echo_cancel: Packet details: Packet Length=22, Channel Id=1, Packet Id=66 Flags=0x00000F00, NLP Threshold=-21(dB), Suppressor Coverage=7(s), Attenuation=2(s), fx_mode=0 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_ECHO_CANCELLER_CONTROL(3) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_set_gain: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_set_gain: Packet details: Packet Length=12, Channel Id=1, Packet Id=91 Gain: In=0.0(dB), Out=0.0(dB) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_SET_GAINS(28) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_agc_control: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_agc_control: Packet details: Packet Length=14, Channel Id=1, Packet Id=98 AGC control: In= off, 0(dBm), Out=off, 0(dBm) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: invalid event -1 of type 0 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_digit_relay_config: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_digit_relay_config: Packet details: Packet Length=10, Channel Id=1, Packet Id=85 Mode=4 Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_DIGIT_RELAY(22) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_vad_enable: Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_vad_enable: Packet details: Packet Length=8, Channel Id=1, Packet Id=77 VAD=0 (OFF) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.815: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_VAD_DISABLE(14) Apr 28 17:23:37.815: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.819: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:37.819: //4585/B98777B3B479/CCAPI/cc_api_voice_mode_event: Call Id=4585 Apr 28 17:23:37.819: //4585/B98777B3B479/CCAPI/cc_api_voice_mode_event: Call Entry(Context=0x2BFFCD90) Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/hpi_call_progress_detect: Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/hpi_call_progress_detect: exit@7502 Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/hpi_inband_det_ctrl: Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/hpi_inband_det_ctrl: exit@11263 Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/hpi_fax_enable: Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/hpi_inband_det_ctrl: Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/hpi_inband_det_ctrl: Packet details: Packet Length=16, Channel Id=1, Packet Id=111 SignalType=2, Mode=2, Signal suppression bitmap 1 Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:37.819: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_INBAND_DETECTOR_CONTROL(45) Apr 28 17:23:37.819: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:37.819: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:37.819: //4584/B98777B3B479/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bKytr0D0yj4D35K From: "Nick" ;tag=vr6UyBBp8gU0p To: ;tag=81FFBF5C-19E1 Date: Sat, 28 Apr 2012 17:23:37 GMT Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec CSeq: 27480844 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2(1)T1, Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 243 v=0 o=CiscoSystemsSIP-GW-UserAgent 6507 194 IN IP4 10.50.47.19 s=SIP Call c=IN IP4 10.50.47.19 t=0 0 m=audio 28356 RTP/AVP 0 101 c=IN IP4 10.50.47.19 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:10 Apr 28 17:23:39.427: //4585/B98777B3B479/CCAPI/cc_api_call_alert: Interface=0x2BC79A0C, Progress Indication=NULL(0), Signal Indication=NOT PRESENT(255) Apr 28 17:23:39.427: //4585/B98777B3B479/CCAPI/cc_api_call_alert: Call Entry(Retry Count=0, Responsed=TRUE) Apr 28 17:23:39.427: //4584/B98777B3B479/CCAPI/ccCallAlert: Progress Indication=NULL(0), Signal Indication=NOT PRESENT(255) Apr 28 17:23:39.427: //4584/B98777B3B479/CCAPI/ccCallAlert: Call Entry(Responsed=TRUE, Alert Sent=TRUE) Apr 28 17:23:39.427: //4584/B98777B3B479/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bKytr0D0yj4D35K From: "Nick" ;tag=vr6UyBBp8gU0p To: ;tag=81FFBF5C-19E1 Date: Sat, 28 Apr 2012 17:23:37 GMT Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec CSeq: 27480844 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Server: Cisco-SIPGateway/IOS-15.2(1)T1, Content-Length: 0 Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.915: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:40.915: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=309: Signaling=0, ComfortNoise=0 Transmit Duration=3090(ms): Voice=3090(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=136: Signaling=0, ComfortNoise=0 Receive Duration=2580(ms): Voice=1320(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=0, Early=3Receive inactive duration=0(ms) Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=65(ms), Watermark(ms): Low=65, High=85 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=160(ms), Interpolative=0(ms), Silence=20(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=2 Clock compensation:early packet=30(ms) drift=0(ms) Discarded by JB:late=0(ms), silence=30(ms) JB size change:decrease=30(ms), increase=30(ms) Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-37.8(dBm0), Mean=-29.3(linear PCM); RX: Power=-79.3(dBm0), Mean=-19.6(linear PCM) BG Noise=-84.4(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:23:40.919: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=0,len=0) dc(id=0,len=0) Apr 28 17:23:41.623: %ISDN-6-CONNECT: Interface Serial0/0/0:22 is now connected to 28881010 N/A Apr 28 17:23:41.623: //4585/B98777B3B479/CCAPI/cc_api_call_connected: Interface=0x2BC79A0C, Data Bitmask=0x1, Progress Indication=NULL(0), Connection Handle=0 Apr 28 17:23:41.623: //4585/B98777B3B479/CCAPI/cc_api_call_connected: Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0) Apr 28 17:23:41.623: //4584/B98777B3B479/CCAPI/ccCallConnect: Progress Indication=NULL(0), Data Bitmask=0x1 Apr 28 17:23:41.623: //4584/B98777B3B479/CCAPI/ccCallConnect: Call Entry(Connected=TRUE, Responsed=TRUE) Apr 28 17:23:41.623: //4584/B98777B3B479/CCAPI/ccCallNotify: Data Bitmask=0x7, Call Id=4584 Apr 28 17:23:41.627: //4584/B98777B3B479/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bKytr0D0yj4D35K From: "Nick" ;tag=vr6UyBBp8gU0p To: ;tag=81FFBF5C-19E1 Date: Sat, 28 Apr 2012 17:23:37 GMT Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec CSeq: 27480844 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2(1)T1, Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 243 v=0 o=CiscoSystemsSIP-GW-UserAgent 6507 194 IN IP4 10.50.47.19 s=SIP Call c=IN IP4 10.50.47.19 t=0 0 m=audio 28356 RTP/AVP 0 101 c=IN IP4 10.50.47.19 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:10 Apr 28 17:23:42.123: //4584/B98777B3B479/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bKytr0D0yj4D35K From: "Nick" ;tag=vr6UyBBp8gU0p To: ;tag=81FFBF5C-19E1 Date: Sat, 28 Apr 2012 17:23:37 GMT Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec CSeq: 27480844 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Remote-Party-ID: ;party=called;screen=no;privacy=off Contact: Supported: replaces Supported: sdp-anat Server: Cisco-SIPGateway/IOS-15.2(1)T1, Supported: timer Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 243 v=0 o=CiscoSystemsSIP-GW-UserAgent 6507 194 IN IP4 10.50.47.19 s=SIP Call c=IN IP4 10.50.47.19 t=0 0 m=audio 28356 RTP/AVP 0 101 c=IN IP4 10.50.47.19 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:10 Apr 28 17:23:42.359: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: ACK sip:28881010@10.50.47.19:5060 SIP/2.0 Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bKZ3HSFUFp1pSrF Max-Forwards: 70 From: "Nick" ;tag=vr6UyBBp8gU0p To: ;tag=81FFBF5C-19E1 Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec CSeq: 27480844 ACK Contact: Content-Length: 0 Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.183: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:43.183: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=536: Signaling=0, ComfortNoise=0 Transmit Duration=5360(ms): Voice=5360(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=220: Signaling=0, ComfortNoise=0 Receive Duration=4850(ms): Voice=2140(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=2, Early=3Receive inactive duration=0(ms) Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=85(ms), Watermark(ms): Low=55, High=85 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=400(ms), Interpolative=0(ms), Silence=60(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=6 Clock compensation:early packet=30(ms) drift=0(ms) Discarded by JB:late=20(ms), silence=40(ms) JB size change:decrease=40(ms), increase=60(ms) Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-13.8(dBm0), Mean=-28.6(linear PCM); RX: Power=-64.7(dBm0), Mean=-20.9(linear PCM) BG Noise=-66.4(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:23:43.191: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:46.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=830: Signaling=0, ComfortNoise=0 Transmit Duration=8300(ms): Voice=8300(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=474: Signaling=0, ComfortNoise=0 Receive Duration=7790(ms): Voice=4670(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=2, Early=3Receive inactive duration=0(ms) Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=75(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=830(ms), Interpolative=0(ms), Silence=60(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=6 Clock compensation:early packet=30(ms) drift=0(ms) Discarded by JB:late=20(ms), silence=60(ms) JB size change:decrease=60(ms), increase=70(ms) Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-36.8(dBm0), Mean=-23.9(linear PCM); RX: Power=-21.7(dBm0), Mean=-22.5(linear PCM) BG Noise=-53.1(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:23:46.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.735: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:48.735: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=1091: Signaling=0, ComfortNoise=0 Transmit Duration=10910(ms): Voice=10910(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=698: Signaling=0, ComfortNoise=0 Receive Duration=10400(ms): Voice=6900(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=3Receive inactive duration=0(ms) Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=85(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=1180(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=30(ms) drift=0(ms) Discarded by JB:late=30(ms), silence=80(ms) JB size change:decrease=80(ms), increase=100(ms) Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-29.0(dBm0), Mean=-20.5(linear PCM); RX: Power=-37.3(dBm0), Mean=-23.3(linear PCM) BG Noise=-64.4(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:23:48.739: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.479: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:23:55.479: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:23:55.487: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:55.487: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.487: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:23:55.487: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=1766: Signaling=0, ComfortNoise=0 Transmit Duration=17660(ms): Voice=17660(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=1278: Signaling=0, ComfortNoise=0 Receive Duration=17150(ms): Voice=12730(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=3Receive inactive duration=0(ms) Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=65(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=2120(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=30(ms) drift=0(ms) Discarded by JB:late=30(ms), silence=100(ms) JB size change:decrease=100(ms), increase=100(ms) Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-19.4(dBm0), Mean=-21.5(linear PCM); RX: Power=-41.0(dBm0), Mean=-23.7(linear PCM) BG Noise=-73.0(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:23:55.491: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.115: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:01.115: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=2329: Signaling=0, ComfortNoise=0 Transmit Duration=23290(ms): Voice=23290(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=1762: Signaling=0, ComfortNoise=0 Receive Duration=22780(ms): Voice=17560(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=3Receive inactive duration=0(ms) Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=65(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=2920(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=30(ms) drift=0(ms) Discarded by JB:late=30(ms), silence=100(ms) JB size change:decrease=100(ms), increase=100(ms) Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-21.4(dBm0), Mean=-21.0(linear PCM); RX: Power=-79.3(dBm0), Mean=-23.7(linear PCM) BG Noise=-84.4(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:01.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:01.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:01.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:01.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:03.623: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2EB timestamp 0x32410 Apr 28 17:24:03.623: << Pt:101 Evt:1 Pkt:07 00 50 Apr 28 17:24:03.635: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2EC timestamp 0x32410 Apr 28 17:24:03.635: << Pt:101 Evt:1 Pkt:07 00 A0 Apr 28 17:24:03.647: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2ED timestamp 0x32410 Apr 28 17:24:03.647: << Pt:101 Evt:1 Pkt:07 00 F0 Apr 28 17:24:03.655: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2EE timestamp 0x32410 Apr 28 17:24:03.655: << Pt:101 Evt:1 Pkt:07 01 40 Apr 28 17:24:03.663: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2EF timestamp 0x32410 Apr 28 17:24:03.663: << Pt:101 Evt:1 Pkt:07 01 90 Apr 28 17:24:03.675: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F0 timestamp 0x32410 Apr 28 17:24:03.675: << Pt:101 Evt:1 Pkt:07 01 E0 Apr 28 17:24:03.683: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F1 timestamp 0x32410 Apr 28 17:24:03.683: << Pt:101 Evt:1 Pkt:07 02 30 Apr 28 17:24:03.695: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F2 timestamp 0x32410 Apr 28 17:24:03.695: << Pt:101 Evt:1 Pkt:07 02 80 Apr 28 17:24:03.703: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F3 timestamp 0x32410 Apr 28 17:24:03.703: << Pt:101 Evt:1 Pkt:07 02 D0 Apr 28 17:24:03.715: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F4 timestamp 0x32410 Apr 28 17:24:03.715: << Pt:101 Evt:1 Pkt:07 03 20 Apr 28 17:24:03.723: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F5 timestamp 0x32410 Apr 28 17:24:03.723: << Pt:101 Evt:1 Pkt:07 03 70 Apr 28 17:24:03.735: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F6 timestamp 0x32410 Apr 28 17:24:03.735: << Pt:101 Evt:1 Pkt:07 03 C0 Apr 28 17:24:03.743: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F7 timestamp 0x32410 Apr 28 17:24:03.743: << Pt:101 Evt:1 Pkt:07 04 10 Apr 28 17:24:03.755: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F8 timestamp 0x32410 Apr 28 17:24:03.755: << Pt:101 Evt:1 Pkt:07 04 60 Apr 28 17:24:03.763: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2F9 timestamp 0x32410 Apr 28 17:24:03.763: << Pt:101 Evt:1 Pkt:07 04 B0 Apr 28 17:24:03.775: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2FA timestamp 0x32410 Apr 28 17:24:03.775: << Pt:101 Evt:1 Pkt:07 05 00 Apr 28 17:24:03.787: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2FB timestamp 0x32410 Apr 28 17:24:03.787: << Pt:101 Evt:1 Pkt:07 05 50 Apr 28 17:24:03.795: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2FC timestamp 0x32410 Apr 28 17:24:03.795: << Pt:101 Evt:1 Pkt:07 05 A0 Apr 28 17:24:03.803: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2FD timestamp 0x32410 Apr 28 17:24:03.803: << Pt:101 Evt:1 Pkt:07 05 F0 Apr 28 17:24:03.815: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2FE timestamp 0x32410 Apr 28 17:24:03.815: << Pt:101 Evt:1 Pkt:07 06 40 Apr 28 17:24:03.823: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE2FF timestamp 0x32410 Apr 28 17:24:03.823: << Pt:101 Evt:1 Pkt:07 06 90 Apr 28 17:24:03.835: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE300 timestamp 0x32410 Apr 28 17:24:03.835: << Pt:101 Evt:1 Pkt:07 06 E0 Apr 28 17:24:03.843: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE301 timestamp 0x32410 Apr 28 17:24:03.843: << Pt:101 Evt:1 Pkt:07 07 30 Apr 28 17:24:03.855: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE302 timestamp 0x32410 Apr 28 17:24:03.855: << Pt:101 Evt:1 Pkt:07 07 80 Apr 28 17:24:03.863: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE303 timestamp 0x32410 Apr 28 17:24:03.863: << Pt:101 Evt:1 Pkt:07 07 D0 Apr 28 17:24:03.875: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE304 timestamp 0x32410 Apr 28 17:24:03.875: << Pt:101 Evt:1 Pkt:07 08 20 Apr 28 17:24:03.883: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE305 timestamp 0x32410 Apr 28 17:24:03.883: << Pt:101 Evt:1 Pkt:07 08 70 Apr 28 17:24:03.895: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE306 timestamp 0x32410 Apr 28 17:24:03.895: << Pt:101 Evt:1 Pkt:87 08 C0 Apr 28 17:24:03.895: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE307 timestamp 0x32410 Apr 28 17:24:03.895: << Pt:101 Evt:1 Pkt:87 08 C0 Apr 28 17:24:03.895: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE308 timestamp 0x32410 Apr 28 17:24:03.895: << Pt:101 Evt:1 Pkt:87 08 C0 Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.839: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:04.839: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=2702: Signaling=0, ComfortNoise=0 Transmit Duration=27020(ms): Voice=27020(ms), FAX=0(ms) Transmit inactive duration=4(ms) Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=2082: Signaling=0, ComfortNoise=0 Receive Duration=26510(ms): Voice=20460(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=4Receive inactive duration=0(ms) Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=65(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317859(ms), interarrival_jitter=11 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:04.847: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=3430(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=40(ms) drift=0(ms) Discarded by JB:late=30(ms), silence=110(ms) JB size change:decrease=110(ms), increase=110(ms) Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-26.2(dBm0), Mean=-19.6(linear PCM); RX: Power=-79.3(dBm0), Mean=-26.9(linear PCM) BG Noise=-84.4(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:04.851: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.743: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:09.743: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:09.747: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:09.747: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.747: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:09.747: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:09.747: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=3192: Signaling=0, ComfortNoise=0 Transmit Duration=31920(ms): Voice=31920(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=2504: Signaling=0, ComfortNoise=0 Receive Duration=31410(ms): Voice=24680(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=4Receive inactive duration=0(ms) Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=65(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317859(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=4110(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=40(ms) drift=0(ms) Discarded by JB:late=30(ms), silence=110(ms) JB size change:decrease=110(ms), increase=110(ms) Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-29.7(dBm0), Mean=-19.7(linear PCM); RX: Power=-14.5(dBm0), Mean=-23.7(linear PCM) BG Noise=-58.8(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:09.751: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.167: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:15.167: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=3734: Signaling=0, ComfortNoise=0 Transmit Duration=37340(ms): Voice=37340(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=2970: Signaling=0, ComfortNoise=0 Receive Duration=36830(ms): Voice=29340(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=4Receive inactive duration=0(ms) Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=65(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317859(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=4870(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=40(ms) drift=0(ms) Discarded by JB:late=30(ms), silence=110(ms) JB size change:decrease=110(ms), increase=110(ms) Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-14.2(dBm0), Mean=-20.1(linear PCM); RX: Power=-21.1(dBm0), Mean=-20.9(linear PCM) BG Noise=-59.0(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:15.171: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.127: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:20.127: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=4230: Signaling=0, ComfortNoise=0 Transmit Duration=42300(ms): Voice=42300(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=3396: Signaling=0, ComfortNoise=0 Receive Duration=41790(ms): Voice=33600(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=4Receive inactive duration=0(ms) Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=55(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=5570(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=40(ms) drift=10(ms) Discarded by JB:late=30(ms), silence=110(ms) JB size change:decrease=120(ms), increase=110(ms) Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-23.3(dBm0), Mean=-20.2(linear PCM); RX: Power=-34.7(dBm0), Mean=-19.8(linear PCM) BG Noise=-52.2(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:20.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:21.163: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8CF timestamp 0x54830 Apr 28 17:24:21.163: << Pt:101 Evt:1 Pkt:07 00 50 Apr 28 17:24:21.175: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D0 timestamp 0x54830 Apr 28 17:24:21.175: << Pt:101 Evt:1 Pkt:07 00 A0 Apr 28 17:24:21.183: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D1 timestamp 0x54830 Apr 28 17:24:21.183: << Pt:101 Evt:1 Pkt:07 00 F0 Apr 28 17:24:21.195: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D2 timestamp 0x54830 Apr 28 17:24:21.195: << Pt:101 Evt:1 Pkt:07 01 40 Apr 28 17:24:21.203: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D3 timestamp 0x54830 Apr 28 17:24:21.203: << Pt:101 Evt:1 Pkt:07 01 90 Apr 28 17:24:21.215: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D4 timestamp 0x54830 Apr 28 17:24:21.215: << Pt:101 Evt:1 Pkt:07 01 E0 Apr 28 17:24:21.223: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D5 timestamp 0x54830 Apr 28 17:24:21.223: << Pt:101 Evt:1 Pkt:07 02 30 Apr 28 17:24:21.235: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D6 timestamp 0x54830 Apr 28 17:24:21.235: << Pt:101 Evt:1 Pkt:07 02 80 Apr 28 17:24:21.243: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D7 timestamp 0x54830 Apr 28 17:24:21.243: << Pt:101 Evt:1 Pkt:07 02 D0 Apr 28 17:24:21.255: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D8 timestamp 0x54830 Apr 28 17:24:21.255: << Pt:101 Evt:1 Pkt:07 03 20 Apr 28 17:24:21.267: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8D9 timestamp 0x54830 Apr 28 17:24:21.267: << Pt:101 Evt:1 Pkt:07 03 70 Apr 28 17:24:21.275: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8DA timestamp 0x54830 Apr 28 17:24:21.275: << Pt:101 Evt:1 Pkt:07 03 C0 Apr 28 17:24:21.283: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8DB timestamp 0x54830 Apr 28 17:24:21.283: << Pt:101 Evt:1 Pkt:07 04 10 Apr 28 17:24:21.295: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8DC timestamp 0x54830 Apr 28 17:24:21.295: << Pt:101 Evt:1 Pkt:07 04 60 Apr 28 17:24:21.303: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8DD timestamp 0x54830 Apr 28 17:24:21.303: << Pt:101 Evt:1 Pkt:07 04 B0 Apr 28 17:24:21.315: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8DE timestamp 0x54830 Apr 28 17:24:21.315: << Pt:101 Evt:1 Pkt:07 05 00 Apr 28 17:24:21.323: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8DF timestamp 0x54830 Apr 28 17:24:21.323: << Pt:101 Evt:1 Pkt:07 05 50 Apr 28 17:24:21.335: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E0 timestamp 0x54830 Apr 28 17:24:21.335: << Pt:101 Evt:1 Pkt:07 05 A0 Apr 28 17:24:21.343: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E1 timestamp 0x54830 Apr 28 17:24:21.343: << Pt:101 Evt:1 Pkt:07 05 F0 Apr 28 17:24:21.355: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E2 timestamp 0x54830 Apr 28 17:24:21.355: << Pt:101 Evt:1 Pkt:07 06 40 Apr 28 17:24:21.363: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E3 timestamp 0x54830 Apr 28 17:24:21.363: << Pt:101 Evt:1 Pkt:07 06 90 Apr 28 17:24:21.375: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E4 timestamp 0x54830 Apr 28 17:24:21.375: << Pt:101 Evt:1 Pkt:07 06 E0 Apr 28 17:24:21.387: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E5 timestamp 0x54830 Apr 28 17:24:21.387: << Pt:101 Evt:1 Pkt:07 07 30 Apr 28 17:24:21.395: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E6 timestamp 0x54830 Apr 28 17:24:21.395: << Pt:101 Evt:1 Pkt:07 07 80 Apr 28 17:24:21.407: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E7 timestamp 0x54830 Apr 28 17:24:21.407: << Pt:101 Evt:1 Pkt:07 07 D0 Apr 28 17:24:21.415: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E8 timestamp 0x54830 Apr 28 17:24:21.415: << Pt:101 Evt:1 Pkt:07 08 20 Apr 28 17:24:21.427: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8E9 timestamp 0x54830 Apr 28 17:24:21.427: << Pt:101 Evt:1 Pkt:07 08 70 Apr 28 17:24:21.435: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8EA timestamp 0x54830 Apr 28 17:24:21.435: << Pt:101 Evt:1 Pkt:87 08 C0 Apr 28 17:24:21.435: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8EB timestamp 0x54830 Apr 28 17:24:21.435: << Pt:101 Evt:1 Pkt:87 08 C0 Apr 28 17:24:21.435: s=VoIP d=DSP payload 0x65 ssrc 0x592DAA91 sequence 0xE8EC timestamp 0x54830 Apr 28 17:24:21.435: << Pt:101 Evt:1 Pkt:87 08 C0 Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.579: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:25.579: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=4776: Signaling=0, ComfortNoise=0 Transmit Duration=47760(ms): Voice=47760(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=3866: Signaling=0, ComfortNoise=0 Receive Duration=47250(ms): Voice=38010(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=5Receive inactive duration=0(ms) Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=55(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317859(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=6310(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=50(ms) drift=10(ms) Discarded by JB:late=30(ms), silence=120(ms) JB size change:decrease=130(ms), increase=120(ms) Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:25.587: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-15.9(dBm0), Mean=-16.7(linear PCM); RX: Power=-24.7(dBm0), Mean=-22.8(linear PCM) BG Noise=-58.7(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:25.591: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=9 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.295: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:30.295: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=5247: Signaling=0, ComfortNoise=0 Transmit Duration=52470(ms): Voice=52470(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=4270: Signaling=0, ComfortNoise=0 Receive Duration=51960(ms): Voice=42060(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=5Receive inactive duration=0(ms) Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=55(ms), Watermark(ms): Low=55, High=95 Clock Offset=-465317859(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=6970(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=50(ms) drift=10(ms) Discarded by JB:late=30(ms), silence=120(ms) JB size change:decrease=130(ms), increase=120(ms) Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-28.6(dBm0), Mean=-18.5(linear PCM); RX: Power=-21.8(dBm0), Mean=-23.7(linear PCM) BG Noise=-70.2(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:30.299: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:35.119: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Received: BYE sip:28881010@10.50.47.19:5060 SIP/2.0 Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bK0cBjHp0SyZFBB Max-Forwards: 70 From: "Nick" ;tag=vr6UyBBp8gU0p To: ;tag=81FFBF5C-19E1 Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec CSeq: 27480845 BYE Contact: User-Agent: Configured by 2600hz! Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: precondition, path, replaces Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 Apr 28 17:24:35.119: //4585/B98777B3B479/CCAPI/ccGenerateToneInfo: Stop Tone On Digit=FALSE, Tone=Null, Tone Direction=Sum Network, Params=0x0, Call Id=4585 Apr 28 17:24:35.119: //4584/B98777B3B479/CCAPI/cc_api_call_disconnected: Cause Value=16, Interface=0x2B460AA4, Call Id=4584 Apr 28 17:24:35.119: //4584/B98777B3B479/CCAPI/cc_api_call_disconnected: Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0) Apr 28 17:24:35.119: //4584/B98777B3B479/CCAPI/ccConferenceDestroy: Conference Id=0x85B, Tag=0x0 Apr 28 17:24:35.119: //4584/B98777B3B479/CCAPI/cc_api_bridge_drop_done: Conference Id=0x85B, Source Interface=0x2B460AA4, Source Call Id=4584, Destination Call Id=4585, Disposition=0x0, Tag=0x0 Apr 28 17:24:35.119: //4585/B98777B3B479/CCAPI/cc_api_bridge_drop_done: Conference Id=0x85B, Source Interface=0x2BC79A0C, Source Call Id=4585, Destination Call Id=4584, Disposition=0x0, Tag=0x0 Apr 28 17:24:35.119: //4584/B98777B3B479/CCAPI/cc_generic_bridge_done: Conference Id=0x85B, Source Interface=0x2BC79A0C, Source Call Id=4585, Destination Call Id=4584, Disposition=0x0, Tag=0x0 Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_voice_config_params: Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_pak_suppress: Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_pak_suppress: Start packet suppression Packet details: Packet Length=10, Channel Id=1, Packet Id=106 Mode=0 Codec=1 Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.119: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GEN_PACKET_CONTROL(41) Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.119: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.119: //4584/B98777B3B479/CCAPI/ccCallDisconnect: Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16) Apr 28 17:24:35.119: //4584/B98777B3B479/CCAPI/ccCallDisconnect: Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16) Apr 28 17:24:35.119: //4585/B98777B3B479/CCAPI/ccCallDisconnect: Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0) Apr 28 17:24:35.119: //4585/B98777B3B479/CCAPI/ccCallDisconnect: Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16) Apr 28 17:24:35.119: //4585/B98777B3B479/CCAPI/cc_api_get_transfer_info: Transfer Number Is Null Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=543 request_id=1 reset_flag=0 conferee_id=0 query_no=6 dsprm_type=32 Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.119: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:35.119: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.123: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.123: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=5730: Signaling=0, ComfortNoise=0 Transmit Duration=57300(ms): Voice=57300(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=4684: Signaling=0, ComfortNoise=0 Receive Duration=56790(ms): Voice=46210(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=5Receive inactive duration=0(ms) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=45(ms), Watermark(ms): Low=45, High=95 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=7650(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=50(ms) drift=20(ms) Discarded by JB:late=30(ms), silence=120(ms) JB size change:decrease=140(ms), increase=120(ms) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-13.3(dBm0), Mean=-19.0(linear PCM); RX: Power=-53.0(dBm0), Mean=-23.1(linear PCM) BG Noise=-63.3(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=19 request_id=6 reset_flag=0 conferee_id=0 query_no=3 dsprm_type=32 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.131: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.131: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.131: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.131: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.131: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:35.135: //4584/B98777B3B479/CCAPI/cc_api_call_disconnect_done: Disposition=0, Interface=0x2B460AA4, Tag=0x0, Call Id=4584, Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0) Apr 28 17:24:35.135: //4584/B98777B3B479/CCAPI/cc_api_call_disconnect_done: Call Disconnect Event Sent Apr 28 17:24:35.135: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Apr 28 17:24:35.135: :cc_free_feature_vsa freeing 2BF68E78 Apr 28 17:24:35.135: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Apr 28 17:24:35.135: vsacount in free is 1 Apr 28 17:24:35.135: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg: Sent: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.50.47.30:5080;rport;branch=z9hG4bK0cBjHp0SyZFBB From: "Nick" ;tag=vr6UyBBp8gU0p To: ;tag=81FFBF5C-19E1 Date: Sat, 28 Apr 2012 17:24:35 GMT Call-ID: bb4c6ea5-0bf9-1230-f395-000c29ab60ec Server: Cisco-SIPGateway/IOS-15.2(1)T1, CSeq: 27480845 BYE Reason: Q.850;cause=16 P-RTP-Stat: PS=5729,OS=458320,PR=4684,OR=370160,PL=0,JI=10,LA=0,DU=53 Content-Length: 0 Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=5731: Signaling=0, ComfortNoise=0 Transmit Duration=57310(ms): Voice=57310(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=4684: Signaling=0, ComfortNoise=0 Receive Duration=56800(ms): Voice=46210(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=5Receive inactive duration=0(ms) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-12.9(dBm0), Mean=-19.0(linear PCM); RX: Power=-53.7(dBm0), Mean=-23.1(linear PCM) BG Noise=-63.2(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: query_id=575 request_id=8 reset_flag=0 conferee_id=0 query_no=7 dsprm_type=32 Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_tx: Packet details: Packet Length=10, Channel Id=1, Packet Id=86 ResetFlag=FALSE Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_TX_STAT(23) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_rx: Packet details: Packet Length=10, Channel Id=1, Packet Id=87 ResetFlag=FALSE Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_RX_STAT(24) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pd: Playout delay Packet details: Packet Length=10, Channel Id=1, Packet Id=83 ResetFlag=FALSE Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_DELAY(20) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_pe: Playout error Packet details: Packet Length=10, Channel Id=1, Packet Id=84 ResetFlag=FALSE Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_VOICE_PLAYOUT_ERROR(21) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_level: Packet details: Packet Length=8, Channel Id=1, Packet Id=89 Apr 28 17:24:35.139: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.139: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_LEVELS(26) Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.143: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_error: Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_error: Packet details: Packet Length=10, Channel Id=1, Packet Id=6 ResetFlag=FALSE Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.143: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_GET_ERROR_STAT(0) Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.143: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_vq_stats: Packet details: Packet Length=16, Channel Id=1, Packet Id=220 Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.143: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) UNDEFINED(67) Checker Ret: INVALID_ENTRY. Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.143: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_VOICE(2) Apr 28 17:24:35.143: //4585/B98777B3B479/HPI/[0/1:1]/hpi_query_info: exit@10908 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=199 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_tx: Got TX stats Packet details: Packet Length=40, Channel Id=1, Packet Id=199 TX Packets=5732: Signaling=0, ComfortNoise=0 Transmit Duration=57320(ms): Voice=57320(ms), FAX=0(ms) Transmit inactive duration=0(ms) Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=200 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_rx: Got RX stats Packet details: Packet Length=188, Channel Id=1, Packet Id=200 RX Packets=4684: Signaling=0, ComfortNoise=0 Receive Duration=56810(ms): Voice=46210(ms), FAX=0(ms) Packet Counts: OOSequence=0, Bad header=0, Late=3, Early=5Receive inactive duration=0(ms) Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=196 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pd: Got Playout Delay stats... Packet details: Packet Length=92, Channel Id=1, Packet Id=196 RX Delay: CurrentEstimate=45(ms), Watermark(ms): Low=45, High=95 Clock Offset=-465317779(ms), interarrival_jitter=10 playout delay mode (actual)=1 min playout delay (actual)=40 max playout delay (actual)=990 nominal playout delay (actual) =60 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=197 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_pe: Got Playout Error stats Packet details: Packet Length=152, Channel Id=1, Packet Id=197 Concealment: Predictive=7670(ms), Interpolative=0(ms), Silence=70(ms), Retroactive=1(ms) Buffer overflow discard duration=0(ms) Talkspurt Detection Errors=7 Clock compensation:early packet=50(ms) drift=20(ms) Discarded by JB:late=30(ms), silence=120(ms) JB size change:decrease=140(ms), increase=120(ms) Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=202 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_lvl: Got Level stats... Packet details: Packet Length=44, Channel Id=1, Packet Id=202 TX: Power=-12.9(dBm0), Mean=-19.0(linear PCM); RX: Power=-49.2(dBm0), Mean=-23.1(linear PCM) BG Noise=-63.2(dBm0), ERL=51.0(dB), ACOM=51.1(dB), Activity=1 Reflector locations(ms): 16 2 0, Max Reflector=0(ms) 2 ECAN Control Words: 0x0000000D 0x000007C2, ECAN Version=0x00000101.0x00000506 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=198 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_error: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_error: Got Error stats Packet details: Packet Length=64, Channel Id=1, Packet Id=198 RX Dropped=2, TX Dropped=0, RX Control=14920 TX Control=55449, TX Control Dropped=0 DSP mode_channel_1=1, DSP mode_channel_2=2, Last RX Control=0xE3D703E Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_message: Packet details: Packet Id=221 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ stats responsePacket details: Packet Length=244, Channel Id=1, Packet Id=221 msg_id=138, msg_length=236 Apr 28 17:24:35.151: //4585/B98777B3B479/HPI/[0/1:1]/hpi_receive_query_vq_stats: Got VQ Keyhole Stats. jitter(id=3,len=6) kfactor(id=5,len=54) cr(id=137,len=24) cs(id=136,len=26) g107(id=134,len=34) config(id=2,len=38) vaf(id=4,len=30) dc(id=0,len=0) Apr 28 17:24:35.151: %ISDN-6-DISCONNECT: Interface Serial0/0/0:22 disconnected from 28881010 , call lasted 53 seconds Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_stop_service: Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_idle_service: Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_idle_service: Packet details: Packet Length=8, Channel Id=1, Packet Id=68 Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.251: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_VOICE(2) E_HPI_DSP_IDLE_MODE(5) Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.251: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_IDLE(1) Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_close_service: Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_close_service: srvc_id 0 media_type 0 Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_close_service: Close Channel Packet details: Packet Length=8, Channel Id=1, Packet Id=75 Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_send_message: Apr 28 17:24:35.251: hpi [0/0/0:23 (4585)] DSP [0/0x0] S_HPI_IDLE(1) E_HPI_DSP_CLOSE_VOICE_CHANNEL(12) Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/caplog_hpi_msg_log: Apr 28 17:24:35.251: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_CLOSED(0) Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_dspmgr_close: Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_dspmgr_close: Apr 28 17:24:35.251: //4585/B98777B3B479/HPI/[0/1:1]/hpi_dsprm_callback: Apr 28 17:24:35.251: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_CLOSED(0) Apr 28 17:24:35.251: hpi [0/0/0:23 (4585)] DSP [0/0x0] -> S_HPI_CLOSED(0) Apr 28 17:24:35.251: //-1/xxxxxxxxxxxx/HPI/[]/hpi_dspmgr_close_cleanup: Apr 28 17:24:35.251: //-1/xxxxxxxxxxxx/HPI/[]/hpi_dspmgr_close_cleanup: Apr 28 17:24:35.251: //4585/B98777B3B479/CCAPI/cc_api_call_disconnect_done: Disposition=0, Interface=0x2BC79A0C, Tag=0x0, Call Id=4585, Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0) Apr 28 17:24:35.251: //4585/B98777B3B479/CCAPI/cc_api_call_disconnect_done: Call Disconnect Event Sent Apr 28 17:24:35.251: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Apr 28 17:24:35.251: :cc_free_feature_vsa freeing 2BF69118 Apr 28 17:24:35.251: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Apr 28 17:24:35.251: vsacount in free is 0 s-vgw01-hkg#
... View more
04-28-2012
01:58 AM
Hi, thanks for the pointers on debug options. 'debug voip rtp session named-event' does generate events as in the origonal post so I am sure they are getting there. ccsip and ccapi generate nothing at the time of the dtmf being entered. there is output from call setup but not sure if that is relevant. hpi all output is below and this is the only call going through the gateway so all relates to the relevant call Apr 28 08:51:31.326: //-1/2F48AFC9B40D/CCAPI/cc_api_display_ie_subfields: cc_api_call_setup_ind_common: cisco-username=35576500 ----- ccCallInfo IE subfields ----- cisco-ani=35576500 cisco-anitype=0 cisco-aniplan=0 cisco-anipi=0 cisco-anisi=1 dest=28881010 cisco-desttype=0 cisco-destplan=0 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=0 cisco-rdnplan=0 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Apr 28 08:51:31.326: //-1/2F48AFC9B40D/CCAPI/cc_api_call_setup_ind_common: Interface=0x2B460AA4, Call Info( Calling Number=35576500,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed), Called Number=28881010(TON=Unknown, NPI=Unknown), Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Incoming Dial-peer=3, Progress Indication=NULL(0), Calling IE Present=TRUE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=4548 Apr 28 08:51:31.326: //-1/2F48AFC9B40D/CCAPI/ccCheckClipClir: In: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed) Apr 28 08:51:31.326: //-1/2F48AFC9B40D/CCAPI/ccCheckClipClir: Out: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed) Apr 28 08:51:31.326: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 08:51:31.326: :cc_get_feature_vsa malloc success Apr 28 08:51:31.326: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 08:51:31.326: cc_get_feature_vsa count is 1 Apr 28 08:51:31.326: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 08:51:31.326: :FEATURE_VSA attributes are: feature_name:0,feature_time:737578624,feature_id:4544 Apr 28 08:51:31.326: //4548/2F48AFC9B40D/CCAPI/cc_api_call_setup_ind_common: Set Up Event Sent; Call Info(Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed), Called Number=28881010(TON=Unknown, NPI=Unknown)) Apr 28 08:51:31.326: //4548/2F48AFC9B40D/CCAPI/cc_process_call_setup_ind: Event=0x3150F328 Apr 28 08:51:31.330: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search: Try with the demoted called number 28881010 Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccCallSetContext: Context=0x2BFEA028 Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/cc_process_call_setup_ind: >>>>CCAPI handed cid 4548 with tag 3 to app "_ManagedAppProcess_Default" Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccCallProceeding: Progress Indication=NULL(0) Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccCallSetupRequest: Destination=, Calling IE Present=TRUE, Mode=0, Outgoing Dial-peer=7, Params=0x31918E5C, Progress Indication=NULL(0) Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccCheckClipClir: In: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed) Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccCheckClipClir: Out: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed) Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccCallSetupRequest: Destination Pattern=[1-9]......., Called Number=28881010, Digit Strip=TRUE Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccCallSetupRequest: Calling Number=35576500(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed), Called Number=28881010(TON=Unknown, NPI=Unknown), Redirect Number=, Display Info=Nick Account Number=35576500, Final Destination Flag=TRUE, Guid=2F48AFC9-9046-11E1-B40D-891BB6D70534, Outgoing Dial-peer=7 Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/cc_api_display_ie_subfields: ccCallSetupRequest: cisco-username=35576500 ----- ccCallInfo IE subfields ----- cisco-ani=35576500 cisco-anitype=0 cisco-aniplan=0 cisco-anipi=0 cisco-anisi=1 dest=28881010 cisco-desttype=0 cisco-destplan=0 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=0 cisco-rdnplan=0 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccIFCallSetupRequestPrivate: Interface=0x2BC79A0C, Interface Type=6, Destination=, Mode=0x0, Call Params(Calling Number=35576500,(Calling Name=Nick)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed), Called Number=28881010(TON=Unknown, NPI=Unknown), Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=7, Call Count On=FALSE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=) Apr 28 08:51:31.330: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 08:51:31.330: :cc_get_feature_vsa malloc success Apr 28 08:51:31.330: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 08:51:31.330: cc_get_feature_vsa count is 2 Apr 28 08:51:31.330: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Apr 28 08:51:31.330: :FEATURE_VSA attributes are: feature_name:0,feature_time:737579296,feature_id:4545 Apr 28 08:51:31.330: //4549/2F48AFC9B40D/CCAPI/ccIFCallSetupRequestPrivate: SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1 Apr 28 08:51:31.330: //4549/2F48AFC9B40D/CCAPI/ccCallSetContext: Context=0x31918E0C Apr 28 08:51:31.330: //4548/2F48AFC9B40D/CCAPI/ccSaveDialpeerTag: Outgoing Dial-peer=7 Apr 28 08:51:31.542: //4549/2F48AFC9B40D/CCAPI/cc_api_call_proceeding: Interface=0x2BC79A0C, Progress Indication=INBAND(8) Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/ccCallCutProgress: Progress Indication=INBAND(8), Signal Indication=INTERCEPT(2), Cause Value=0 Voice Call Send Alert=FALSE, Call Entry(Alert Sent=FALSE) Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/ccCallCutProgress: Call Entry(Responsed=TRUE) Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/ccConferenceCreate: (confID=0x3126EC88, callID1=0x11C4, gcid=2F494BF1-904611E1-B410891B-B6D70534, tag=0x0) Apr 28 08:51:31.542: //4549/2F48AFC9B40D/CCAPI/ccConferenceCreate: (confID=0x3126EC88, callID2=0x11C5, gcid=2F494BF1-904611E1-B410891B-B6D70534, tag=0x0) Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/ccConferenceCreate: Conference Id=0x3126EC88, Call Id1=4548, Call Id2=4549, Tag=0x0 Apr 28 08:51:31.542: //4548/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream: Apr 28 08:51:31.542: cc_api_get_xcode_stream : 4803 Apr 28 08:51:31.542: //4548/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream: Apr 28 08:51:31.542: cc_api_get_xcode_stream : 4803 Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/cc_api_bridge_done: Conference Id=0x849, Source Interface=0x2B460AA4, Source Call Id=4548, Destination Call Id=4549, Disposition=0x0, Tag=0x0 Apr 28 08:51:31.542: //4549/2F48AFC9B40D/CCAPI/cc_api_bridge_done: Conference Id=0x849, Source Interface=0x2BC79A0C, Source Call Id=4549, Destination Call Id=4548, Disposition=0x0, Tag=0xFFFFFFFF Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/cc_generic_bridge_done: Conference Id=0x849, Source Interface=0x2BC79A0C, Source Call Id=4549, Destination Call Id=4548, Disposition=0x0, Tag=0xFFFFFFFF Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/ccConferenceCreate: Call Entry(Conference Id=0x849, Destination Call Id=4549) Apr 28 08:51:31.542: //4549/2F48AFC9B40D/CCAPI/ccConferenceCreate: Call Entry(Conference Id=0x849, Destination Call Id=4548) Apr 28 08:51:31.542: //4549/2F48AFC9B40D/CCAPI/cc_api_caps_ind: Destination Interface=0x2B460AA4, Destination Call Id=4548, Source Call Id=4549, Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1, Modem=0x2, Codec Bytes=20, Signal Type=3) Apr 28 08:51:31.542: //4549/2F48AFC9B40D/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=1000(ms), Fax Nom=300(ms)) Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/cc_api_caps_ind: Destination Interface=0x2BC79A0C, Destination Call Id=4549, Source Call Id=4548, Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1, Modem=0x0, Codec Bytes=80, Signal Type=2) Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=1000(ms), Fax Nom=300(ms)) Apr 28 08:51:31.542: //4548/2F48AFC9B40D/CCAPI/cc_api_caps_ack: Destination Interface=0x2BC79A0C, Destination Call Id=4549, Source Call Id=4548, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=80, Signal Type=2, Seq Num Start=3428) Apr 28 08:51:31.546: //4549/2F48AFC9B40D/CCAPI/cc_api_caps_ack: Destination Interface=0x2B460AA4, Destination Call Id=4548, Source Call Id=4549, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=80, Signal Type=2, Seq Num Start=3428) Apr 28 08:51:31.546: //4548/2F48AFC9B40D/CCAPI/ccCallNotify: Data Bitmask=0x7, Call Id=4548 Apr 28 08:51:31.546: //4548/2F48AFC9B40D/CCAPI/cc_process_notify_bridge_done: Conference Id=0x849, Call Id1=4548, Call Id2=4549 Apr 28 08:51:31.546: //4549/2F48AFC9B40D/CCAPI/cc_api_voice_mode_event: Call Id=4549 Apr 28 08:51:31.546: //4549/2F48AFC9B40D/CCAPI/cc_api_voice_mode_event: Call Entry(Context=0x31918E0C) Apr 28 08:51:33.390: //4549/2F48AFC9B40D/CCAPI/cc_api_call_alert: Interface=0x2BC79A0C, Progress Indication=NULL(0), Signal Indication=NOT PRESENT(255) Apr 28 08:51:33.390: //4549/2F48AFC9B40D/CCAPI/cc_api_call_alert: Call Entry(Retry Count=0, Responsed=TRUE) Apr 28 08:51:33.390: //4548/2F48AFC9B40D/CCAPI/ccCallAlert: Progress Indication=NULL(0), Signal Indication=NOT PRESENT(255) Apr 28 08:51:33.390: //4548/2F48AFC9B40D/CCAPI/ccCallAlert: Call Entry(Responsed=TRUE, Alert Sent=TRUE) Apr 28 08:51:35.570: %ISDN-6-CONNECT: Interface Serial0/0/0:22 is now connected to 28881010 N/A Apr 28 08:51:35.570: //4549/2F48AFC9B40D/CCAPI/cc_api_call_connected: Interface=0x2BC79A0C, Data Bitmask=0x1, Progress Indication=NULL(0), Connection Handle=0 Apr 28 08:51:35.570: //4549/2F48AFC9B40D/CCAPI/cc_api_call_connected: Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0) Apr 28 08:51:35.570: //4548/2F48AFC9B40D/CCAPI/ccCallConnect: Progress Indication=NULL(0), Data Bitmask=0x1 Apr 28 08:51:35.570: //4548/2F48AFC9B40D/CCAPI/ccCallConnect: Call Entry(Connected=TRUE, Responsed=TRUE) Apr 28 08:51:35.574: //4548/2F48AFC9B40D/CCAPI/ccCallNotify: Data Bitmask=0x7, Call Id=4548
... View more
Created by
bernarddmurphy
in IP Telephony and Phones
12-15-2012
12-15-2012
thanks num-exp works great !
Created by
bernarddmurphy
in IP Telephony and Phones
12-15-2012
12-15-2012
Hi Chris, It's just the voice gateway. no communication manager or any
other cisco products involved...
Created by
bernarddmurphy
in IP Telephony and Phones
12-15-2012
12-15-2012
I am struggling with something that sounds like it ought to be simple.I
have a 2901 UC voice gateway...
04-29-2012
You can close this question, the cisco was not at fault and the SIP PBX
was not setting the first ma...
04-28-2012
Ok, here is the whole thing. The DTMF digit sent was '1' and was tried
twice, both unsuccessful.term...
Public Statistics
| Date Registered | 04-26-2012 02:38 PM |
| Date Last Visited | 08-18-2017 03:53 AM |
| Total Messages Posted | 7 |
