×

Warning message

  • Cisco Support Forums is in Read Only mode while the site is being migrated.
  • Cisco Support Forums is in Read Only mode while the site is being migrated.

DTMF from SIP to ISDN

Unanswered Question
Apr 26th, 2012
User Badges:

Hi, I have a Cisco 2901 voice gateway connected to a T1 ISDN circuit which is configured with the below dial-peers that allow a call from SIP to PSTN to which I am calling a number that goes to an IVR where I need to enter DTMF. This work fine and the DTMF is succesful if I just go from my SIP Useragent directly to Cisco gateway and out to PSTN. This is all using RFC2833 DTMF and codec PCMU.


However when I place my PBX (Freeswitch) in the call flow the generated DTMF digits sent to Cisco show up in a 'debug voip rtp session' trace so they definitely get there but don't go any further out to Q931 or ISDN.


Any idea where to look next or why this is happening ?


dial-peer voice 3 voip

description inbound peer from voip

session protocol sipv2

incoming called-number .

voice-class codec 1

dtmf-relay rtp-nte

dtmf-interworking rtp-nte

no vad

!

dial-peer voice 4 pots

description outbound Hong Kong Local numbers

destination-pattern [1-9].......

port 0/0/0:23



output from 'debug voip rtp session'


Apr 26 21:33:36.846: voip_rtp_update_cisco_payloads: The updated cisco reserved payload types are:

         cisco_codec_fax_pt = 96, cisco_codec_fax_ack_pt = 97,

         cisco_rtp_dtmf_relay_pt = 121, cisco_fax_relay_pt = 122,

         cisco_cas_pt = 123, cisco_clear_channel_pt = 125,

         cisco_rtp_type_annex_B = 123, cisco_lmr_tone_pt = 0,

         cisco_nte_tone_pt = 0

Apr 26 21:33:36.846: voip_rtp_set_non_rtp_call: Non-RTP call end

Apr 26 21:33:36.846: voip_rtp_exchange_context_info

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info, dstvdbptr: 2B460AA4, dstCallID 4348, gccb: 2BFA3D80, xmitFunc 254309D4,context 31978A68

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info Xmit Info node current values xmit_info->dstvdbptr: 2B460AA4, xmit_info->dstCallID 4348, xmit_info->xmitFunc 254309D4, xmit_info->context 31978A68

Apr 26 21:33:36.846:  voip xmit info count: 1

Apr 26 21:33:36.846: voip_rtp_update_v150_payloads:

Apr 26 21:33:36.846: voip_rtp_update_v150_payloads: The updated v150 payload types are:

         cisco_cme_sprt_pt = 0

Apr 26 21:33:36.846: voip_rtp_exchange_context_info

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info, dstvdbptr: 2BC79A0C, dstCallID 4348, gccb: 2BFA3D80, xmitFunc 254309D4,context 31978A68

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info Xmit Info node current values xmit_info->dstvdbptr: 2BC79A0C, xmit_info->dstCallID 4348, xmit_info->xmitFunc 254309D4, xmit_info->context 31978A68

Apr 26 21:33:36.846:  voip xmit info count: 1

Apr 26 21:33:36.846: voip_rtp_exchange_context_info

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info, dstvdbptr: 2BC79A0C, dstCallID 4348, gccb: 2BFA3D80, xmitFunc 254309D4,context 31978A68

Apr 26 21:33:36.846:  voip_rtp_update_xmit_info Xmit Info node current values xmit_info->dstvdbptr: 2BC79A0C, xmit_info->dstCallID 4348, xmit_info->xmitFunc 254309D4, xmit_info->context 31978A68

Apr 26 21:33:36.846:  voip xmit info count: 1

Apr 26 21:33:36.846: //4347/xxxxxxxxxxxx/RTP//Event/voip_rtcp_new: do_rtcp=1

Apr 26 21:33:36.846: voip_rtcp_start_session:

Apr 26 21:33:36.846: voip_rtcp_start_session: start sessionMedia Inactivity Criteria is 0

Apr 26 21:33:40.962: %ISDN-6-CONNECT: Interface Serial0/0/0:22 is now connected to 28881010 N/AMedia Inactivity Criteria is 0Media Inactivity Criteria is 0Media Inactivity Criteria is 0

Apr 26 21:33:51.358:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE68 timestamp 0x1BD00

Apr 26 21:33:51.358:  <<<Rcv> Pt:101    Evt:1       Pkt:07 00 50

Apr 26 21:33:51.370:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE69 timestamp 0x1BD00

Apr 26 21:33:51.370:  <<<Rcv> Pt:101    Evt:1       Pkt:07 00 A0

Apr 26 21:33:51.378:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE6A timestamp 0x1BD00

Apr 26 21:33:51.378:  <<<Rcv> Pt:101    Evt:1       Pkt:07 00 F0

Apr 26 21:33:51.390:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE6B timestamp 0x1BD00

Apr 26 21:33:51.390:  <<<Rcv> Pt:101    Evt:1       Pkt:07 01 40

Apr 26 21:33:51.398:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE6C timestamp 0x1BD00

Apr 26 21:33:51.398:  <<<Rcv> Pt:101    Evt:1       Pkt:07 01 90

Apr 26 21:33:51.410:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE6D timestamp 0x1BD00

Apr 26 21:33:51.410:  <<<Rcv> Pt:101    Evt:1       Pkt:07 01 E0

Apr 26 21:33:51.418:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE6E timestamp 0x1BD00

Apr 26 21:33:51.418:  <<<Rcv> Pt:101    Evt:1       Pkt:07 02 30

Apr 26 21:33:51.430:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE6F timestamp 0x1BD00

Apr 26 21:33:51.430:  <<<Rcv> Pt:101    Evt:1       Pkt:07 02 80

Apr 26 21:33:51.438:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE70 timestamp 0x1BD00

Apr 26 21:33:51.438:  <<<Rcv> Pt:101    Evt:1       Pkt:07 02 D0

Apr 26 21:33:51.450:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE71 timestamp 0x1BD00

Apr 26 21:33:51.450:  <<<Rcv> Pt:101    Evt:1       Pkt:07 03 20

Apr 26 21:33:51.458:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE72 timestamp 0x1BD00

Apr 26 21:33:51.458:  <<<Rcv> Pt:101    Evt:1       Pkt:07 03 70

Apr 26 21:33:51.470:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE73 timestamp 0x1BD00

Apr 26 21:33:51.470:  <<<Rcv> Pt:101    Evt:1       Pkt:07 03 C0

Apr 26 21:33:51.478:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE74 timestamp 0x1BD00

Apr 26 21:33:51.478:  <<<Rcv> Pt:101    Evt:1       Pkt:07 04 10

Apr 26 21:33:51.490:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE75 timestamp 0x1BD00

Apr 26 21:33:51.490:  <<<Rcv> Pt:101    Evt:1       Pkt:07 04 60

Apr 26 21:33:51.498:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE76 timestamp 0x1BD00

Apr 26 21:33:51.498:  <<<Rcv> Pt:101    Evt:1       Pkt:07 04 B0

Apr 26 21:33:51.510:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE77 timestamp 0x1BD00

Apr 26 21:33:51.510:  <<<Rcv> Pt:101    Evt:1       Pkt:07 05 00

Apr 26 21:33:51.518:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE78 timestamp 0x1BD00

Apr 26 21:33:51.518:  <<<Rcv> Pt:101    Evt:1       Pkt:07 05 50

Apr 26 21:33:51.530:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE79 timestamp 0x1BD00

Apr 26 21:33:51.530:  <<<Rcv> Pt:101    Evt:1       Pkt:07 05 A0

Apr 26 21:33:51.538:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE7A timestamp 0x1BD00

Apr 26 21:33:51.538:  <<<Rcv> Pt:101    Evt:1       Pkt:07 05 F0

Apr 26 21:33:51.550:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE7B timestamp 0x1BD00

Apr 26 21:33:51.550:  <<<Rcv> Pt:101    Evt:1       Pkt:07 06 40

Apr 26 21:33:51.558:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE7C timestamp 0x1BD00

Apr 26 21:33:51.558:  <<<Rcv> Pt:101    Evt:1       Pkt:07 06 90

Apr 26 21:33:51.570:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE7D timestamp 0x1BD00

Apr 26 21:33:51.570:  <<<Rcv> Pt:101    Evt:1       Pkt:07 06 E0

Apr 26 21:33:51.578:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE7E timestamp 0x1BD00

Apr 26 21:33:51.578:  <<<Rcv> Pt:101    Evt:1       Pkt:07 07 30

Apr 26 21:33:51.590:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE7F timestamp 0x1BD00

Apr 26 21:33:51.590:  <<<Rcv> Pt:101    Evt:1       Pkt:07 07 80

Apr 26 21:33:51.598:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE80 timestamp 0x1BD00

Apr 26 21:33:51.598:  <<<Rcv> Pt:101    Evt:1       Pkt:07 07 D0

Apr 26 21:33:51.610:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE81 timestamp 0x1BD00

Apr 26 21:33:51.610:  <<<Rcv> Pt:101    Evt:1       Pkt:07 08 20

Apr 26 21:33:51.618:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE82 timestamp 0x1BD00

Apr 26 21:33:51.618:  <<<Rcv> Pt:101    Evt:1       Pkt:07 08 70

Apr 26 21:33:51.630:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE83 timestamp 0x1BD00

Apr 26 21:33:51.630:  <<<Rcv> Pt:101    Evt:1       Pkt:87 08 C0

Apr 26 21:33:51.630:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE84 timestamp 0x1BD00

Apr 26 21:33:51.630:  <<<Rcv> Pt:101    Evt:1       Pkt:87 08 C0

Apr 26 21:33:51.630:          s=VoIP d=DSP payload 0x65 ssrc 0x58171B3B sequence 0xFE85 timestamp 0x1BD00

Apr 26 21:33:51.630:  <<<Rcv> Pt:101    Evt:1       Pkt:87 08 C0Media Inactivity Criteria is 0

s-vgw01-hkg#

s-vgw01-hkg#   

  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 0 (0 ratings)
Loading.
Daniele Giordano Fri, 04/27/2012 - 04:53
User Badges:
  • Gold, 750 points or more

Use these debug together:

debug ccsip message

debug voip rtp session

debug isdn q931


and post the output.


Regards.

marmugam Fri, 04/27/2012 - 09:30
User Badges:
  • Cisco Employee,

Hello Bernard,


If it is getting to GW, then if it is not going to IVR across PSTN, then the only chance w.r.t to Cisco GW is  DSP might be dropping it, which I highly doubt. As why would it has to drop only from the PBX vendor and not from Cisco UA. Unless the PBX is not following the appropriate RFC2833 standards. 


++ Does the IVR get any digits at all or they receive some or duplication?


Few things we can try to isolate it:-


++ Just place one call and enable the following debugs:-


debug ccsip message

debug voip rtp session named-evt

debug voip ccapi inout

debug voip hpi all (if the GW is not busy)


Give the debugs and let us know the digits you pressed.


++ Does PBX only supports rfc_2833 can you try any OOB methods to see if it helps.

++ Why you have both relay and internetworking enabled. Can you only try dtmf-relay.

++ Try removing both, so eveything will be sent as inband in VBD, and see if IVR can recognise it.


++ If nothing works, then only option is to go for PCM cpature, to see If DSP did anything to the digits. But I doubt.


Murali

bernarddmurphy Sat, 04/28/2012 - 01:58
User Badges:

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

marmugam Sat, 04/28/2012 - 08:42
User Badges:
  • Cisco Employee,

Hello Bernard,


Logs are not complete, no hpi debugs , no voip rtp session,  debug voip ccapi inout is only till connect stage, I dont see any digit being sent. SO can you call everything to the buffer, make a call press the digits and do "ter len 0" . Log the session, and do sho log and give the log session output.


Murali

bernarddmurphy Sat, 04/28/2012 - 10:28
User Badges:

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:[email protected] 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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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:[email protected]: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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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: [email protected]

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:[email protected]: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: [email protected]

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: [email protected]

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: [email protected]

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#

bernarddmurphy Sun, 04/29/2012 - 06:20
User Badges:

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.

Actions

This Discussion