=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2008.03.11 17:46:28 =~=~=~=~=~=~=~=~=~=~=~= debug cch323 al All CCH323 call tracing is enabled ASM-111-VR#debug voip ccapi inout voip ccapi inout debugging is on ASM-111-VR#debug vtsp session This CLI command is now 'debug voip vtsp session' ASM-111-VR#sh controller e1 E1 0/1/0 is up. Applique type is Channelized E1 - balanced No alarms detected. alarm-trigger is not set Version info Firmware: 20060711, FPGA: 13, spm_count = 0 Framing is CRC4, Line Code is HDB3, Clock Source is Line. CRC Threshold is 320. Reported from firmware is 320. Data in current interval (732 seconds elapsed): 0 Line Code Violations, 0 Path Code Violations 0 Slip Secs, 0 Fr Loss Secs, 0 Line Err Secs, 0 Degraded Mins 0 Errored Secs, 0 Bursty Err Secs, 0 Severely Err Secs, 0 Unavail Secs Total Data (last 24 hours) 0 Line Code Violations, 0 Path Code Violations, 217 Slip Secs, 0 Fr Loss Secs, 0 Line Err Secs, 0 Degraded Mins, 217 Errored Secs, 0 Bursty Err Secs, 0 Severely Err Secs, 0 Unavail Secs --More-- E1 0/1/1 is up. Applique type is Channelized E1 - balanced No alarms detected. alarm-trigger is not set Version info Firmware: 20060711, FPGA: 13, spm_count = 0 Framing is CRC4, Line Code is HDB3, Clock Source is Line. CRC Threshold is 320. Reported from firmware is 320. Data in current interval (741 seconds elapsed): 0 Line Code Violations, 0 Path Code Violations 208 Slip Secs, 0 Fr Loss Secs, 0 Line Err Secs, 0 Degraded Mins 208 Errored Secs, 0 Bursty Err Secs, 0 Severely Err Secs, 0 Unavail Secs Total Data (last 24 hours) 0 Line Code Violations, 0 Path Code Violations, 24549 Slip Secs, 0 Fr Loss Secs, 0 Line Err Secs, 0 Degraded Mins, 24549 Errored Secs, 0 Bursty Err Secs, 0 Severely Err Secs, 0 Unavail Secs ASM-111-VR# sh net ASM-111-VR#sh netwo ASM-111-VR#sh network-clocks Network Clock Configuration --------------------------- Priority Clock Source Clock State Clock Type 1 E1 0/1/0 GOOD E1 10 Backplane GOOD PLL Current Primary Clock Source --------------------------- Priority Clock Source Clock State Clock Type 1 E1 0/1/0 GOOD E1 ASM-111-VR# Mar 11 16:49:01.590: //-1/xxxxxxxxxxxx/CCAPI/ccAppShutdownMode: ccAppShutdownMode: remove it from the queue Mar 11 16:49:16.186: //-1/EB866A8480A6/CCAPI/cc_api_display_ie_subfields: cc_api_call_setup_ind_common: cisco-username= ----- ccCallInfo IE subfields ----- cisco-ani=04917662032618 cisco-anitype=1 cisco-aniplan=1 cisco-anipi=0 cisco-anisi=3 dest=6445 cisco-desttype=2 cisco-destplan=1 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=-1 cisco-rdnplan=-1 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Mar 11 16:49:16.186: //-1/EB866A8480A6/CCAPI/cc_api_call_setup_ind_common: Interface=0x48675B98, Call Info( Calling Number=04917662032618,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Incoming Dial-peer=200, Progress Indication=NULL(0), Calling IE Present=TRUE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1 Mar 11 16:49:16.186: //-1/EB866A8480A6/CCAPI/ccCheckClipClir: In: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:49:16.186: //-1/EB866A8480A6/CCAPI/ccCheckClipClir: Out: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:49:16.186: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:16.186: :cc_get_feature_vsa malloc success Mar 11 16:49:16.186: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:16.186: cc_get_feature_vsa count is 1 Mar 11 16:49:16.186: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:16.186: :FEATURE_VSA attributes are: feature_name:0,fearture_time:1191055160,feature_id:33350 Mar 11 16:49:16.186: //33300/EB866A8480A6/CCAPI/cc_api_call_setup_ind_common: Set Up Event Sent; Call Info(Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN)) Mar 11 16:49:16.190: //33300/EB866A8480A6/CCAPI/cc_process_call_setup_ind: Event=0x46FED938 Mar 11 16:49:16.190: //33300/EB866A8480A6/CCAPI/ccCallSetContext: Context=0x45994E94 Mar 11 16:49:16.190: //33300/EB866A8480A6/CCAPI/cc_process_call_setup_ind: >>>>CCAPI handed cid 33300 with tag 200 to app "_ManagedAppProcess_Default" Mar 11 16:49:16.194: //33300/EB866A8480A6/CCAPI/ccCallProceeding: Progress Indication=NULL(0) Mar 11 16:49:16.198: //33300/EB866A8480A6/CCAPI/ccCallSetupRequest: Destination=, Calling IE Present=TRUE, Mode=0, Outgoing Dial-peer=2000, Params=0x45997A04, Progress Indication=NULL(0) Mar 11 16:49:16.198: //33300/EB866A8480A6/CCAPI/ccCheckClipClir: In: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:49:16.198: //33300/EB866A8480A6/CCAPI/ccCheckClipClir: Out: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:49:16.198: //33300/EB866A8480A6/CCAPI/ccCallSetupRequest: Destination Pattern=6445, Called Number=6445, Digit Strip=FALSE Mar 11 16:49:16.198: //33300/EB866A8480A6/CCAPI/ccCallSetupRequest: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Redirect Number=, Display Info= Account Number=, Final Destination Flag=TRUE, Guid=EB866A84-EEC1-11DC-80A6-001B0C63E550, Outgoing Dial-peer=2000 Mar 11 16:49:16.198: //33300/EB866A8480A6/CCAPI/cc_api_display_ie_subfields: ccCallSetupRequest: cisco-username= ----- ccCallInfo IE subfields ----- cisco-ani=04917662032618 cisco-anitype=1 cisco-aniplan=1 cisco-anipi=0 cisco-anisi=3 dest=6445 cisco-desttype=2 cisco-destplan=1 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=-1 cisco-rdnplan=-1 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Mar 11 16:49:16.198: //33300/EB866A8480A6/CCAPI/ccIFCallSetupRequestPrivate: Interface=0x46C1EC74, Interface Type=1, Destination=, Mode=0x0, Call Params(Calling Number=04917662032618,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=2000, Call Count On=FALSE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=) Mar 11 16:49:16.198: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:16.198: :cc_get_feature_vsa malloc success Mar 11 16:49:16.198: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:16.198: cc_get_feature_vsa count is 2 Mar 11 16:49:16.198: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:16.198: :FEATURE_VSA attributes are: feature_name:0,fearture_time:1191053864,feature_id:33351 Mar 11 16:49:16.198: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: callID=33301 Mar 11 16:49:16.198: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0 Mar 11 16:49:16.198: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0 Mar 11 16:49:16.198: //33301/EB866A8480A6/CCAPI/ccIFCallSetupRequestPrivate: SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1 Mar 11 16:49:16.198: //33301/EB866A8480A6/CCAPI/ccCallSetContext: Context=0x459979B4 Mar 11 16:49:16.198: //33300/EB866A8480A6/CCAPI/ccSaveDialpeerTag: Outgoing Dial-peer=2000 Mar 11 16:49:16.198: //-1/xxxxxxxxxxxx/H323/cch323_get_new_ccb: ccb (0x480CE850) is in use Mar 11 16:49:16.198: //33301/EB866A8480A6/H323/cch323_call_setup: gw_id=1 Mar 11 16:49:16.198: //33301/EB866A8480A6/H323/cch323_call_setup: Inserted ccb Mar 11 16:49:16.198: //-1/xxxxxxxxxxxx/H323/cch323_create_call_info_type_container: cch323_create_call_info_type_container: creating callInfoType container for callID = 33301 Mar 11 16:49:16.198: //33301/EB866A8480A6/H323/cch323_get_caps_chn_info: No peer leg setup params Mar 11 16:49:16.198: //33301/EB866A8480A6/H323/cch323_get_peer_info: Entry Mar 11 16:49:16.198: //33301/EB866A8480A6/H323/cch323_get_peer_info: Have peer Mar 11 16:49:16.198: //33301/EB866A8480A6/H323/cch323_get_peer_info: faxrate[41] proto[3] bitmask[10082] t38_inhibit[0] global_fax[1] t38fax[1] Mar 11 16:49:16.198: //33301/EB866A8480A6/H323/cch323_set_pref_codec_list: Using Voice Class Codec, tag = 2 Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_set_pref_codec_list: First preferred codec(bytes)=5(160) Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_get_peer_info: Preferred codec set to G711_ULAW_64K with Bytes = 160 Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_get_peer_info: Flow Mode set to FLOW_THROUGH Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_get_peer_info: peer: 484CE9D0, peer->voice_peer_tag: 7D0, ccb: 480CE850 Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_set_h323_parms_from_dp: ccb h245addr bits = system[0x0007] Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_set_h323_parms_from_dp: ccb ccm bits = system[0x0028] Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_update_setup_callinfo: callingNumber = 04917662032618 Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_update_setup_callinfo: called_oct3 = 0xA1, calling_oct3 = 0x11, calling_oct3a = 0x83 Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_set_h323_control_options_outgoing: h245 sm mode = 271 Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_set_h323_control_options_outgoing: h323_ctl=0x20 Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_call_setup: No account/pin number available Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_call_setup_normal: Entry Mar 11 16:49:16.202: //33301/EB866A8480A6/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:49:16.206: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:16.210: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xB internal event to H225 SM Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_SETUP while at state H225_IDLE Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/check_qos_and_send_setup: Setup ccb 0x480CE850 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_rotary_validate: No peer_ccb available Mar 11 16:49:16.210: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xE internal event to H225 SM Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_FS_SETUP while at state H225_IDLE Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/idle_fsSetup_hdlr: Setup ccb 0x480CE850 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/idle_fsSetup_hdlr: send_fastStart_setup called Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/send_fastStart_setup: Entry Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_build_local_encoded_fastStartOLCs: state_mc_mode=0x10F on outbound leg Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_build_local_encoded_fastStartOLCs: srcAddress = 0xA160302, h245_lport = 0, flow mode = 1, minimum_qos=0 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/h245_set_local_audio_mask: Near-end Pref Codecs = G711_ULAW_64K Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_generic_open_logical_channel: current codec = 5:160:160 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_generic_open_logical_channel: Codec is G711_ULAW_64K Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_generic_open_logical_channel: Filling in qosCapability field to 0 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/generic_send_setup: Entry Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/generic_send_setup: generic_send_setup: is_overlap = 0, info_complete = 0 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/generic_send_setup: sending calling IE Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/generic_send_setup: ====== PI = 0 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/generic_send_setup: Send infoXCap=144, infoXRate=16, rateMult=0, xMode=128, info_layer1_prot=163 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_h225_copy_send_rawMsg: Copy raw message data to nonStdInfo Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_h225_copy_send_rawMsg: Copy tunnelled GTD/ISUP content Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: (for cch323_h225_copy_send_rawMsg): raw message is 231 bytes: Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 04 03 80 90 A3 18 03 A1 83 81 6C 0F 11 83 34 39 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 31 37 36 36 32 30 33 32 36 31 38 70 0A A1 32 30 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 37 31 35 30 32 34 35 A1 1C BD 9E 81 00 03 67 74 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 64 00 00 00 B2 49 41 4D 2C 0D 0A 50 52 4E 2C 69 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 73 64 6E 2A 2C 2C 41 54 54 34 2A 2C 0D 0A 55 53 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 49 2C 72 61 74 65 2C 63 2C 73 2C 63 2C 31 0D 0A Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 55 53 49 2C 6C 61 79 31 2C 61 6C 61 77 0D 0A 54 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 4D 52 2C 30 30 0D 0A 43 50 4E 2C 30 34 2C 2C 31 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 2C 32 30 37 31 35 30 32 34 35 0D 0A 43 47 4E 2C Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 30 36 2C 2C 31 2C 79 2C 34 2C 34 39 31 37 36 36 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 32 30 33 32 36 31 38 0D 0A 43 50 43 2C 30 39 0D Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 0A 46 43 49 2C 2C 2C 2C 2C 2C 2C 79 2C 0D 0A 47 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 43 49 2C 65 62 38 36 36 61 38 34 65 65 63 31 31 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 31 64 63 38 30 61 36 30 30 31 62 30 63 36 33 65 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_prnt_rawmsg: 35 35 30 0D 0A 0D 0A Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/generic_send_setup: src address = 10.22.3.2; dest address = 10.22.1.18 Mar 11 16:49:16.210: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_REQ_FS_SETUP state Mar 11 16:49:16.210: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 IWF SM Mar 11 16:49:16.210: //33301/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_FASTSTART while at state IWF_IDLE Mar 11 16:49:16.210: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:16.310: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:49:16.310: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:49:16.310: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:49:16.310: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: Retry, fd=2 Mar 11 16:49:16.410: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:49:16.410: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:49:16.410: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:49:16.410: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: Retry, fd=2 Mar 11 16:49:16.510: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:49:16.510: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:49:16.510: //-1/xxxxxxxxxxxx/H323/h323_gw_stop_sock_blocked_timer: fd 2 Mar 11 16:49:16.522: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:16.522: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x47FFCA98, len=80, msgPtr=0x47FFB918 Mar 11 16:49:16.522: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225 Mar 11 16:49:16.522: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type ALERTIND_CHOSEN Mar 11 16:49:16.522: //33301/EB866A8480A6/H323/alert_ind: ====== PI = 0 Mar 11 16:49:16.522: //33301/EB866A8480A6/H323/alert_ind: alert ind ie_bit_mask 0x1260, displayInfo Mar 11 16:49:16.522: //33301/EB866A8480A6/H323/alert_ind: delay H245 address in alert Mar 11 16:49:16.522: //33301/EB866A8480A6/H323/cch323_h225_receiver: ALERTIND_CHOSEN: src address = 10.22.3.2; dest address = 10.22.1.18 Mar 11 16:49:16.522: //33301/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_ALERT_IND while at state H225_REQ_FS_SETUP Mar 11 16:49:16.522: //33301/EB866A8480A6/H323/cch323_get_embedded_obj_from_ccb: ccb=0x480CE850, tag=18, size=83 Mar 11 16:49:16.522: //33301/EB866A8480A6/H323/cch323_get_embedded_obj_from_ccb: Extraction FAILED Mar 11 16:49:16.522: //33301/EB866A8480A6/CCAPI/cc_api_set_delay_xport: CallInfo(delay xport=TRUE) Mar 11 16:49:16.522: //33301/EB866A8480A6/CCAPI/cc_api_call_alert: Interface=0x46C1EC74, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1) Mar 11 16:49:16.522: //33301/EB866A8480A6/CCAPI/cc_api_call_alert: Call Entry(Retry Count=0, Responsed=TRUE) Mar 11 16:49:16.522: //33301/EB866A8480A6/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_SETUP state to H225_REQ_FS_ALERT state Mar 11 16:49:16.522: //33300/EB866A8480A6/CCAPI/ccCallAlert: Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1) Mar 11 16:49:16.522: //33300/EB866A8480A6/CCAPI/ccCallAlert: Call Entry(Responsed=TRUE, AlertSent=TRUE) Mar 11 16:49:16.522: //33300/EB866A8480A6/CCAPI/ccGenerateToneInfo: Stop Tone On Digit=FALSE, Tone=Ring Back, Tone Direction=Network, Params=0x0, Call Id=33300 Mar 11 16:49:16.770: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:16.774: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x47FFCA98, len=131, msgPtr=0x47D7C2C4 Mar 11 16:49:16.774: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225 Mar 11 16:49:16.774: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type PROGRESSIND_CHOSEN Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/progress_ind: ======= PI = 1 cause 0 Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_h225_receiver: PROGRESSIND_CHOSEN: src address = 10.22.3.2; dest address = 10.22.1.18 Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_FS_PROGRESS_IND while at state H225_REQ_FS_ALERT Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_ALERT state to H225_ACC_FS_ALERT state Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_selectFastStart_codecs: Codec: loc(5), rem(5); Bytes: loc(160), Fwd(160), Rev(160) Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_receive_fastStart_cap_response: Send cap ind to peer leg Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_build_olc_for_ccapi: audioFastStartArray=0x484C8170 Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_build_olc_for_ccapi: channel_info ptr=0x47FDF3A0, ccb ptr=0x480CE850 Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_build_olc_for_ccapi: Channel Information: Logical Channel Number (fwd): 1 Logical Channel Number (rev): 129 Channel address (fwd/rev): 0xA160112 RTP Channel (fwd/rev): 56000 RTCP Channel (fwd/rev): 56001 QoS Capability (fwd/rev): 0 Symmetric Audio Codec: 5 Symmetric Audio Codec Bytes: 160 Flow Mode: 0 Silence Suppression: 1 Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_build_olc_for_ccapi: NumOfElements = 1 idx = 1 Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_do_cap_ind: Registry cap_ind is not done Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_FASTSTART while at state IWF_IDLE Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/h245_iwf_set_new_state: changing from IWF_OLC_IDLE state to IWF_OLC_DONE state Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/fastStartIdle: H245_EV_OLC_IN/OUT_DONE sent to olc Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/h245_olc_in_sm: Received H245_EV_OLC_IN_DONE while at state H245_OLC_IN_STATE_IDLE Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/h245_olc_in_set_new_state: Changing from H245_OLC_IN_STATE_IDLE state to H245_OLC_IN_STATE_ESTABLISHED state Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/h245_olc_out_sm: Received H245_EV_OLC_OUT_DONE while at state H245_OLC_OUT_STATE_IDLE Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/h245_olc_out_set_new_state: Changing from H245_OLC_OUT_STATE_IDLE state to H245_OLC_OUT_STATE_ESTABLISHED state Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/h323_open_rtp_stream: Media In-active notification object not attached to ccb Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_set_dtmf_iw_enabled: negotiated dtmf relay: 0, dtmf_iw_enabled: 0, dtmf_sccp_enabled: 0 Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_rtp_open_notify: Entry Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/generic_cut_progress_notify: ====== PI = 1, cause = 0 Mar 11 16:49:16.774: //33301/EB866A8480A6/CCAPI/cc_api_call_cut_progress: Interface=0x46C1EC74, Progress Indication=NOT END TO END ISDN(1), Signal Indication=SIGNAL RINGBACK(1), Cause Value=0 Mar 11 16:49:16.774: //33301/EB866A8480A6/CCAPI/cc_api_call_cut_progress: Call Entry(Responsed=TRUE) Mar 11 16:49:16.774: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x16 internal event to H225 SM Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_FACIL_SWITCH_H245 while at state H225_ACC_FS_ALERT Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_LISTEN_REQ_EVENT Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_h245_connection_sm: state=0, event=0, ccb=480CE850, listen state=0 Mar 11 16:49:16.774: //33301/EB866A8480A6/H323/cch323_h245_connection_sm: H245_LISTEN: Received event H245_LISTEN_REQ_EVENT while at H245_NONE state Mar 11 16:49:16.778: //33301/EB866A8480A6/H323/cch323_h245_set_new_state: Changing from H245_NONE state to H245_WAITING state Mar 11 16:49:16.778: //33301/EB866A8480A6/H323/cch323_h225_set_new_state: Changing from H225_ACC_FS_ALERT state to H225_ALERT state Mar 11 16:49:16.778: //33300/EB866A8480A6/CCAPI/ccCallCutProgress: Progress Indication=NOT END TO END ISDN(1), Signal Indication=SIGNAL RINGBACK(1), Cause Value=0 Voice Call Send Alert=FALSE, Call Entry(AlertSent=TRUE) Mar 11 16:49:16.778: //33300/EB866A8480A6/CCAPI/ccCallCutProgress: Call Entry(Responsed=TRUE) Mar 11 16:49:16.778: //33300/EB866A8480A6/CCAPI/ccGenerateToneInfo: Stop Tone On Digit=FALSE, Tone=Null, Tone Direction=Network, Params=0x0, Call Id=33300 Mar 11 16:49:16.778: //33300/xxxxxxxxxxxx/CCAPI/ccConferenceCreate: (confID=0x473F9370, callID1=0x8214, callID2=0x8215, tag=0x0) Mar 11 16:49:16.778: //33300/EB866A8480A6/CCAPI/ccConferenceCreate: Conference Id=0x473F9370, Call Id1=33300, Call Id2=33301, Tag=0x0 Mar 11 16:49:16.778: //33300/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done: Conference Id=0x4088, Source Interface=0x48675B98, Source Call Id=33300, Destination Call Id=33301, Disposition=0x0, Tag=0xFFFFFFFF Mar 11 16:49:16.778: //33301/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream: Mar 11 16:49:16.778: cc_api_get_xcode_stream : 4368 Mar 11 16:49:16.778: //33301/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done: Conference Id=0x4088, Source Interface=0x46C1EC74, Source Call Id=33301, Destination Call Id=33300, Disposition=0x0, Tag=0x0 Mar 11 16:49:16.778: //33300/EB866A8480A6/CCAPI/cc_generic_bridge_done: Conference Id=0x4088, Source Interface=0x46C1EC74, Source Call Id=33301, Destination Call Id=33300, Disposition=0x0, Tag=0x0 Mar 11 16:49:16.778: //33300/EB866A8480A6/CCAPI/ccConferenceCreate: Call Entry(Conference Id=0x4088, Destination Call Id=33301) Mar 11 16:49:16.778: //33301/EB866A8480A6/CCAPI/ccConferenceCreate: Call Entry(Conference Id=0x4088, Destination Call Id=33300) Mar 11 16:49:16.778: //33300/EB866A8480A6/CCAPI/cc_api_caps_ind: Destination Interface=0x46C1EC74, Destination Call Id=33301, Source Call Id=33300, Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1, Modem=0x2, Codec Bytes=20, Signal Type=3) Mar 11 16:49:16.778: //33300/EB866A8480A6/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=250(ms), Fax Nom=300(ms)) Mar 11 16:49:16.778: //-1/xxxxxxxxxxxx/H323/cch323_post_caps_ind: callID=33301, ExtendedCaps not present Mar 11 16:49:16.782: //33300/EB866A8480A6/CCAPI/cc_process_notify_bridge_done: Conference Id=0x4088, Call Id1=33300, Call Id2=33301 Mar 11 16:49:16.782: //33301/EB866A8480A6/H323/cch323_set_dtmf_iw_enabled: negotiated dtmf relay: 0, dtmf_iw_enabled: 0, dtmf_sccp_enabled: 0 Mar 11 16:49:16.782: //33301/EB866A8480A6/H323/cch323_rtp_open_notify: Entry Mar 11 16:49:16.782: //33301/EB866A8480A6/H323/cch323_caps_ind: gw_id=1 Mar 11 16:49:16.782: //33301/EB866A8480A6/H323/cch323_peer_caps_ind_common: Load DSP with Negotiated (No DP match) codec(5) g711ulaw, Bytes=160 Mar 11 16:49:16.782: //33301/EB866A8480A6/H323/cch323_peer_caps_ind_common: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE Mar 11 16:49:16.782: //33301/EB866A8480A6/H323/cch323_peer_caps_ind_common: cap_modem_proto: 0, cap_modem_codec: 0, cap_modem_redundancy: 0, payload: 100, modem_relay: 0, gw_xid: 1 gw_controlled=0 Mar 11 16:49:16.782: //33301/EB866A8480A6/CCAPI/cc_api_caps_ind: Destination Interface=0x48675B98, Destination Call Id=33300, Source Call Id=33301, Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1, Modem=0x0, Codec Bytes=160, Signal Type=2) Mar 11 16:49:16.782: //33301/EB866A8480A6/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=250(ms), Fax Nom=300(ms)) Mar 11 16:49:16.782: //33301/EB866A8480A6/CCAPI/cc_api_caps_ack: Destination Interface=0x48675B98, Destination Call Id=33300, Source Call Id=33301, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=9388) Mar 11 16:49:16.786: //33300/EB866A8480A6/CCAPI/cc_api_caps_ack: Destination Interface=0x46C1EC74, Destination Call Id=33301, Source Call Id=33300, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=9388) Mar 11 16:49:16.786: //33300/EB866A8480A6/CCAPI/cc_api_voice_mode_event: Call Id=33300 Mar 11 16:49:16.786: //33300/EB866A8480A6/CCAPI/cc_api_voice_mode_event: Call Entry(Context=0x45994E94) Mar 11 16:49:16.786: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1 Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_h245_channel_established_ind: Using fd=4 to send msgs Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_ESTABLISHED_EVENT Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_h245_connection_sm: state=1, event=2, ccb=480CE850, listen state=1 Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_h245_connection_sm: H245_LISTEN: Received event H245_ESTABLISHED_EVENT while at H245_WAITING state Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_h245_set_new_state: Changing from H245_WAITING state to H245_CONNECTED state Mar 11 16:49:16.790: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x2 internal event to H245 IWF SM Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_H245_CONNECTED while at state IWF_IDLE Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/h245_iwf_set_new_state: changing from IWF_IDLE state to IWF_H245_CONNECTED state Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/h245_iwf_set_new_state: changing from IWF_H245_CONNECTED state to IWF_AWAIT_CAP_MSD_RESP state Mar 11 16:49:16.790: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 CAP OUT SM Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_run_h245_cap_out_sm: Received H245_EVENT_CAP_REQ while at state IDLE Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: cch323_send_cap_request: ccb->callID: 33301, ccb->h245.state_mc_mode: 271 Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: Second try for videocaps Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: ccb->callID: 33301, video_cap_mask: 0x0 Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/h245_send_generic_audio_caps: Using DP configured codecs Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/h245_normalize_preferred_codec_list: Near-end Pref Codecs = G711_ULAW_64K Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/h245_send_generic_audio_caps: [reg]audio mask after operation=0x1 Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: Included rtp in caps table Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: Included t38 fax in caps table Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: Included signal in caps table Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: Included alpha in caps table Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: Included hookflash in caps table Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_send_cap_request: Included rtp-nte in caps table Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/h245_cap_out_set_new_state: changing from IDLE state to AWAITING_RESPONSE state Mar 11 16:49:16.790: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 MS SM Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_run_h245_ms_sm: Received event H245_EVENT_MSD while at state H245_MS_NONE Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/cch323_run_h245_ms_sm: Sent MSD Request Mar 11 16:49:16.790: //33301/EB866A8480A6/H323/h245_ms_set_new_state: Changing from H245_MS_NONE state to H245_MS_OUTGOING_WAIT state Mar 11 16:49:16.790: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:49:16.790: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=59, msgPtr=0x48675E38 Mar 11 16:49:16.790: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/cch323_h245_cap_ind: Masks au=0x3 data=0x4 uinp=0x0 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/cch323_run_h245_cap_in_sm: Received H245_EVENT_CAP_IND while at state IDLE Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h245_cap_in_set_new_state: changing from IDLE state to AWAITING_RESPONSE state Mar 11 16:49:16.794: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x4 internal event to H245 IWF SM Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_CAP_IND while at state IWF_AWAIT_CAP_MSD_RESP Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h323_validate_cap_ind: Remote Pref Codecs UnOrdered (0x3) = [G711_ULAW_64K] [G711_ALAW_64K] [] Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h245_handle_cap_ind: TCS received from remote end. Setting h245 status flag H245_CAP_REQUEST_RCVD Mar 11 16:49:16.794: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 CAP IN SM Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/cch323_run_h245_cap_in_sm: Received H245_EVENT_CAP_RESP while at state AWAITING_RESPONSE Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h245_cap_in_set_new_state: changing from AWAITING_RESPONSE state to IDLE state Mar 11 16:49:16.794: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:49:16.794: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=7, msgPtr=0x465D404C Mar 11 16:49:16.794: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/cch323_run_h245_ms_sm: Received event H245_EVENT_MS_IND while at state H245_MS_OUTGOING_WAIT Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/MSDetermination: rtt=50 rsdnum=11526200, ltt=60 lsdnum=5685 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/MSDetermination: Am MASTER, ccb->h245.h245_mdStatus = 0x1 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/cch323_run_h245_ms_sm: MS_Determine_indication to Appl: Sent MSD ACK! Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h245_ms_set_new_state: Changing from H245_MS_OUTGOING_WAIT state to H245_MS_INCOMING_WAIT state Mar 11 16:49:16.794: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x10 internal event to H245 IWF SM Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_MSD_ACK_SENT while at state IWF_AWAIT_CAP_MSD_RESP Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h323_find_negotiated_codec: Audio Mask 0x3, Negotiated Codec G711_ULAW_64K(5) Codec Bytes 160 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h323_find_negotiated_dtmf: peer_data_cap_mask=0x4, peer_user_input_cap_mask=0x0 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/cch323_set_dtmf_iw_enabled: negotiated dtmf relay: 3, dtmf_iw_enabled: 0, dtmf_sccp_enabled: 0 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h323_find_negotiated_dtmf: Negotiated DTMF relay - 0x3 Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/h245_iwf_common_msdacksent: Negotiated codecs and dtmf are initialised in ccb Mar 11 16:49:16.794: //33301/EB866A8480A6/H323/cch323_peer_caps_ack: Sending caps resp event to CAP sm Mar 11 16:49:16.802: //33301/EB866A8480A6/H323/cch323_peer_caps_ack: Sending caps resp event to CAP sm Mar 11 16:49:16.802: //33301/EB866A8480A6/H323/cch323_peer_caps_ack: ccb not interested in caps_ack primitive Mar 11 16:49:16.802: //33301/EB866A8480A6/H323/cch323_peer_caps_ack: Sending caps resp event to CAP sm Mar 11 16:49:16.802: //33301/EB866A8480A6/H323/cch323_peer_caps_ack: ccb not interested in caps_ack primitive Mar 11 16:49:47.771: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x47FFCA98, len=50, msgPtr=0x48675E38 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type RELEASEIND_CHOSEN Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/release_ind: Disconnect cause 0 location code 0 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/h323_set_release_source_for_peer: ownCallId[33301], src[4] Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/cch323_h225_receiver: RELEASEIND_CHOSEN: src address = 10.22.3.2; dest address = 10.22.1.18 Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_RELEASE_IND while at state H225_ALERT Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/cch323_traverse_enum_contact_list: State = 3 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/h323_set_cc_cause_for_spi_err: Categorized cause:127, category:127 Mar 11 16:49:47.775: //33301/EB866A8480A6/CCAPI/cc_api_call_disconnected: Cause Value=127, Interface=0x46C1EC74, Call Id=33301 Mar 11 16:49:47.775: //33301/EB866A8480A6/CCAPI/cc_api_call_disconnected: Call Entry(Responsed=TRUE, Cause Value=127, Retry Count=0) Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=8, msgPtr=0x465D3BE4 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/h245_olc_in_sm: Received H245_EV_OLC_CLC_IND while at state H245_OLC_IN_STATE_ESTABLISHED Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/h245_olc_in_set_new_state: Changing from H245_OLC_IN_STATE_ESTABLISHED state to H245_OLC_IN_STATE_IDLE state Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x1B internal event to H245 IWF SM Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_CLC_IND while at state IWF_OLC_DONE Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/h245_iwf_set_new_state: changing from IWF_OLC_DONE state to IWF_OLC_OUT_DONE state Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 2 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_cleanup_xport: hashDestroy for TcpFDTbl Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x2D internal event to H225 SM Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_CONN_LOST while at state H225_ALERT Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=2, msgPtr=0x465D404C Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_DISCONNECT_EVENT Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/cch323_h245_connection_sm: state=0, event=4, ccb=480CE850, listen state=2 Mar 11 16:49:47.775: //33301/EB866A8480A6/H323/cch323_h245_connection_sm: H245_CONNECT: Received event H245_DISCONNECT_EVENT while at H245_NONE state Mar 11 16:49:47.775: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 4 Mar 11 16:49:47.779: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 3 Mar 11 16:49:47.779: //33301/EB866A8480A6/H323/cch323_gw_process_read_socket: cch323_gw_process_read_socket: H.245 socket error, ccb status = 402924554, call release = 0, call disconnected = 1, fd = 4, rc = 4 Mar 11 16:49:47.779: //33300/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources: release reserved xcoding resource. Mar 11 16:49:47.779: //33301/EB866A8480A6/CCAPI/ccCallSetAAA_Accounting: Accounting=1, Call Id=33301 Mar 11 16:49:47.779: //33300/EB866A8480A6/CCAPI/ccConferenceDestroy: Conference Id=0x4088, Tag=0x0 Mar 11 16:49:47.779: //33300/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done: Conference Id=0x4088, Source Interface=0x48675B98, Source Call Id=33300, Destination Call Id=33301, Disposition=0x0, Tag=0x0 Mar 11 16:49:47.779: //33301/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done: Conference Id=0x4088, Source Interface=0x46C1EC74, Source Call Id=33301, Destination Call Id=33300, Disposition=0x0, Tag=0x0 Mar 11 16:49:47.779: //33300/EB866A8480A6/CCAPI/cc_generic_bridge_done: Conference Id=0x4088, Source Interface=0x46C1EC74, Source Call Id=33301, Destination Call Id=33300, Disposition=0x0, Tag=0x0 Mar 11 16:49:47.779: //33301/EB866A8480A6/CCAPI/ccCallDisconnect: Cause Value=127, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=127) Mar 11 16:49:47.779: //33301/EB866A8480A6/CCAPI/ccCallDisconnect: Cause Value=127, Call Entry(Responsed=TRUE, Cause Value=127) Mar 11 16:49:47.779: //33301/EB866A8480A6/CCAPI/cc_api_get_transfer_info: Transfer Number Is Null Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_do_call_disconnect: gw_id=1, discCause=127 Mar 11 16:49:47.783: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x9 internal event to H225 SM Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_ALERT Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_h225_set_new_state: Changing from H225_ALERT state to H225_IDLE state Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_call_generic_cleanup: Disconnected flag 1 Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_store_call_history_entry: Trying to store call history/remove call_info while RTP session exists Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_store_call_history_entry: Call Active Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_store_call_history_entry: Call History Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_H245_DISCONN while at state IWF_ACTIVE Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_DISCONNECT_EVENT Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_h245_connection_sm: state=0, event=4, ccb=480CE850, listen state=0 Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/cch323_h245_connection_sm: H245_CONNECT: Received event H245_DISCONNECT_EVENT while at H245_NONE state Mar 11 16:49:47.783: //33301/EB866A8480A6/H323/h245_iwf_set_new_state: changing from IWF_ACTIVE state to IWF_IDLE state Mar 11 16:49:47.783: //33301/EB866A8480A6/CCAPI/cc_api_call_disconnect_done: Disposition=0, Interface=0x46C1EC74, Tag=0x0, Call Id=33301, Call Entry(Disconnect Cause=127, Voice Class Cause Code=0, Retry Count=0) Mar 11 16:49:47.783: //33301/EB866A8480A6/CCAPI/cc_api_call_disconnect_done: Call Disconnect Event Sent Mar 11 16:49:47.783: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:49:47.783: :cc_free_feature_vsa freeing 46FE0A20 Mar 11 16:49:47.783: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:49:47.783: vsacount in free is 1 Mar 11 16:49:47.783: //-1/xxxxxxxxxxxx/H323/cch323_call_generic_cleanup: Freeing ccb (0x480CE850) Mar 11 16:49:47.787: //33300/EB866A8480A6/CCAPI/ccCallSetupRequest: Destination=, Calling IE Present=TRUE, Mode=0, Outgoing Dial-peer=1017, Params=0x45996BA4, Progress Indication=NULL(0) Mar 11 16:49:47.787: //33300/EB866A8480A6/CCAPI/ccCheckClipClir: In: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:49:47.787: //33300/EB866A8480A6/CCAPI/ccCheckClipClir: Out: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:49:47.787: //33300/EB866A8480A6/CCAPI/ccCallSetupRequest: Destination Pattern=64.., Called Number=6445, Digit Strip=FALSE Mar 11 16:49:47.787: //33300/EB866A8480A6/CCAPI/ccCallSetupRequest: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Redirect Number=, Display Info= Account Number=, Final Destination Flag=TRUE, Guid=EB866A84-EEC1-11DC-80A6-001B0C63E550, Outgoing Dial-peer=1017 Mar 11 16:49:47.787: //33300/EB866A8480A6/CCAPI/cc_api_display_ie_subfields: ccCallSetupRequest: cisco-username= ----- ccCallInfo IE subfields ----- cisco-ani=04917662032618 cisco-anitype=1 cisco-aniplan=1 cisco-anipi=0 cisco-anisi=3 dest=6445 cisco-desttype=2 cisco-destplan=1 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=-1 cisco-rdnplan=-1 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Mar 11 16:49:47.787: //33300/EB866A8480A6/CCAPI/ccIFCallSetupRequestPrivate: Interface=0x46C1EC74, Interface Type=1, Destination=, Mode=0x0, Call Params(Calling Number=04917662032618,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=1017, Call Count On=FALSE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=) Mar 11 16:49:47.791: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:47.791: :cc_get_feature_vsa malloc success Mar 11 16:49:47.791: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:47.791: cc_get_feature_vsa count is 2 Mar 11 16:49:47.791: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:49:47.791: :FEATURE_VSA attributes are: feature_name:0,fearture_time:1191053864,feature_id:33352 Mar 11 16:49:47.791: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: callID=33302 Mar 11 16:49:47.791: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0 Mar 11 16:49:47.791: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0 Mar 11 16:49:47.791: //33302/EB866A8480A6/CCAPI/ccIFCallSetupRequestPrivate: SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1 Mar 11 16:49:47.791: //33302/EB866A8480A6/CCAPI/ccCallSetContext: Context=0x45996B54 Mar 11 16:49:47.791: //33300/EB866A8480A6/CCAPI/ccSaveDialpeerTag: Outgoing Dial-peer=1017 Mar 11 16:49:47.791: //-1/xxxxxxxxxxxx/H323/cch323_get_new_ccb: ccb (0x480CE850) is in use Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_call_setup: gw_id=1 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_call_setup: Inserted ccb Mar 11 16:49:47.791: //-1/xxxxxxxxxxxx/H323/cch323_create_call_info_type_container: cch323_create_call_info_type_container: creating callInfoType container for callID = 33302 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_get_caps_chn_info: No peer leg setup params Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_get_peer_info: Entry Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_get_peer_info: Have peer Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_get_peer_info: faxrate[41] proto[3] bitmask[10082] t38_inhibit[0] global_fax[1] t38fax[1] Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_set_pref_codec_list: Using Voice Class Codec, tag = 1 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_set_pref_codec_list: First preferred codec(bytes)=6(160) Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_get_peer_info: Preferred codec set to G711_ALAW_64K with Bytes = 160 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_get_peer_info: Flow Mode set to FLOW_THROUGH Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_get_peer_info: peer: 45841E90, peer->voice_peer_tag: 3F9, ccb: 480CE850 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_set_h323_parms_from_dp: ccb h245addr bits = system[0x0007] Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_set_h323_parms_from_dp: ccb ccm bits = system[0x0028] Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_update_setup_callinfo: callingNumber = 04917662032618 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_update_setup_callinfo: called_oct3 = 0xA1, calling_oct3 = 0x11, calling_oct3a = 0x83 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_set_h323_control_options_outgoing: h245 sm mode = 271 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_set_h323_control_options_outgoing: h323_ctl=0x20 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_call_setup: No account/pin number available Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:49:47.791: //33302/EB866A8480A6/H323/cch323_call_setup_normal: Entry Mar 11 16:49:47.795: //33302/EB866A8480A6/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:49:47.931: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:47.931: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xB internal event to H225 SM Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_SETUP while at state H225_IDLE Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/check_qos_and_send_setup: Setup ccb 0x480CE850 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_rotary_validate: No peer_ccb available Mar 11 16:49:47.931: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xE internal event to H225 SM Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_FS_SETUP while at state H225_IDLE Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/idle_fsSetup_hdlr: Setup ccb 0x480CE850 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/idle_fsSetup_hdlr: send_fastStart_setup called Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/send_fastStart_setup: Entry Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_build_local_encoded_fastStartOLCs: state_mc_mode=0x10F on outbound leg Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_build_local_encoded_fastStartOLCs: srcAddress = 0xA160302, h245_lport = 0, flow mode = 1, minimum_qos=0 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/h245_set_local_audio_mask: Near-end Pref Codecs = G711_ALAW_64K G711_ULAW_64K G729IETF Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: current codec = 6:160:160 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: Codec is G711_ALAW_64K Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: Filling in qosCapability field to 0 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: current codec = 5:160:160 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: Codec is G711_ULAW_64K Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: Filling in qosCapability field to 0 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: current codec = 16:20:20 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: Codec is G729IETF Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_generic_open_logical_channel: Filling in qosCapability field to 0 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/generic_send_setup: Entry Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/generic_send_setup: generic_send_setup: is_overlap = 0, info_complete = 0 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/generic_send_setup: sending calling IE Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/generic_send_setup: ====== PI = 0 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/generic_send_setup: Send infoXCap=144, infoXRate=16, rateMult=0, xMode=128, info_layer1_prot=163 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_h225_copy_send_rawMsg: Copy raw message data to nonStdInfo Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_h225_copy_send_rawMsg: Copy tunnelled GTD/ISUP content Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: (for cch323_h225_copy_send_rawMsg): raw message is 231 bytes: Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 04 03 80 90 A3 18 03 A1 83 81 6C 0F 11 83 34 39 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 31 37 36 36 32 30 33 32 36 31 38 70 0A A1 32 30 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 37 31 35 30 32 34 35 A1 1C BD 9E 81 00 03 67 74 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 64 00 00 00 B2 49 41 4D 2C 0D 0A 50 52 4E 2C 69 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 73 64 6E 2A 2C 2C 41 54 54 34 2A 2C 0D 0A 55 53 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 49 2C 72 61 74 65 2C 63 2C 73 2C 63 2C 31 0D 0A Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 55 53 49 2C 6C 61 79 31 2C 61 6C 61 77 0D 0A 54 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 4D 52 2C 30 30 0D 0A 43 50 4E 2C 30 34 2C 2C 31 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 2C 32 30 37 31 35 30 32 34 35 0D 0A 43 47 4E 2C Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 30 36 2C 2C 31 2C 79 2C 34 2C 34 39 31 37 36 36 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 32 30 33 32 36 31 38 0D 0A 43 50 43 2C 30 39 0D Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 0A 46 43 49 2C 2C 2C 2C 2C 2C 2C 79 2C 0D 0A 47 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 43 49 2C 65 62 38 36 36 61 38 34 65 65 63 31 31 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 31 64 63 38 30 61 36 30 30 31 62 30 63 36 33 65 Mar 11 16:49:47.931: //33302/EB866A8480A6/H323/cch323_prnt_rawmsg: 35 35 30 0D 0A 0D 0A Mar 11 16:49:47.935: //33302/EB866A8480A6/H323/generic_send_setup: src address = 10.22.3.2; dest address = 10.193.0.18 Mar 11 16:49:47.935: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:49:47.935: //33302/EB866A8480A6/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_REQ_FS_SETUP state Mar 11 16:49:47.935: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 IWF SM Mar 11 16:49:47.935: //33302/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_FASTSTART while at state IWF_IDLE Mar 11 16:49:47.935: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:48.035: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:49:48.035: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:49:48.035: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:49:48.035: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: Retry, fd=2 Mar 11 16:49:48.135: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:49:48.135: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:49:48.135: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:49:48.135: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: Retry, fd=2 Mar 11 16:49:48.235: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:49:48.235: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:49:48.235: //-1/xxxxxxxxxxxx/H323/h323_gw_stop_sock_blocked_timer: fd 2 Mar 11 16:49:48.363: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:49:48.363: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x47FFDBA8, len=45, msgPtr=0x48675E38 Mar 11 16:49:48.363: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225 Mar 11 16:49:48.363: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type RELEASEIND_CHOSEN Mar 11 16:49:48.363: //33302/EB866A8480A6/H323/release_ind: Disconnect cause 1 location code 0 Mar 11 16:49:48.363: //-1/xxxxxxxxxxxx/H323/h323_set_release_source_for_peer: ownCallId[33302], src[4] Mar 11 16:49:48.363: //33302/EB866A8480A6/H323/cch323_h225_receiver: RELEASEIND_CHOSEN: src address = 10.22.3.2; dest address = 10.193.0.18 Mar 11 16:49:48.363: //33302/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_RELEASE_IND while at state H225_REQ_FS_SETUP Mar 11 16:49:48.363: //33302/EB866A8480A6/H323/cch323_traverse_enum_contact_list: State = 2 Mar 11 16:49:48.363: //33302/EB866A8480A6/CCAPI/cc_api_call_disconnected: Cause Value=1, Interface=0x46C1EC74, Call Id=33302 Mar 11 16:49:48.363: //33302/EB866A8480A6/CCAPI/cc_api_call_disconnected: Call Entry(Responsed=TRUE, Cause Value=1, Retry Count=0) Mar 11 16:49:48.367: //33300/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources: release reserved xcoding resource. Mar 11 16:49:48.367: //33302/EB866A8480A6/CCAPI/ccCallSetAAA_Accounting: Accounting=0, Call Id=33302 Mar 11 16:49:48.367: //33302/EB866A8480A6/CCAPI/ccCallDisconnect: Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=1) Mar 11 16:49:48.367: //33302/EB866A8480A6/CCAPI/ccCallDisconnect: Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1) Mar 11 16:49:48.367: //33302/EB866A8480A6/CCAPI/cc_api_get_transfer_info: Transfer Number Is Null Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/cch323_do_call_disconnect: gw_id=1, discCause=1 Mar 11 16:49:48.367: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x9 internal event to H225 SM Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_REQ_FS_SETUP Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/cch323_h225_send_release: Cause = 1; Location = 0 Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/cch323_h225_send_release: h225TerminateRequest: src address = 169214722; dest address = 10.193.0.18 Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_SETUP state to H225_IDLE state Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/cch323_call_generic_cleanup: Disconnected flag 1 Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/cch323_store_call_history_entry: Call Active Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/cch323_store_call_history_entry: Call History Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:49:48.367: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 2 Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/run_h245_iwf_sm: received IWF_EV_H245_DISCONN while at state IWF_IDLE Mar 11 16:49:48.367: //33302/EB866A8480A6/H323/defaultHdlr: DEFAULT: Received IWF_EV_H245_DISCONN in state IWF_IDLE Mar 11 16:49:48.367: //-1/xxxxxxxxxxxx/H323/cch323_cleanup_xport: hashDestroy for TcpFDTbl Mar 11 16:49:48.367: //33302/EB866A8480A6/CCAPI/cc_api_call_disconnect_done: Disposition=0, Interface=0x46C1EC74, Tag=0x0, Call Id=33302, Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0) Mar 11 16:49:48.367: //33302/EB866A8480A6/CCAPI/cc_api_call_disconnect_done: Call Disconnect Event Sent Mar 11 16:49:48.367: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:49:48.367: :cc_free_feature_vsa freeing 46FE0A20 Mar 11 16:49:48.367: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:49:48.367: vsacount in free is 1 Mar 11 16:49:48.371: //-1/xxxxxxxxxxxx/H323/cch323_call_generic_cleanup: Freeing ccb (0x480CE850) Mar 11 16:49:48.375: //33300/EB866A8480A6/CCAPI/ccCallDisconnect: Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0) Mar 11 16:49:48.375: //33300/EB866A8480A6/CCAPI/ccCallDisconnect: Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1) Mar 11 16:49:48.375: //33300/EB866A8480A6/CCAPI/cc_api_get_transfer_info: Transfer Number Is Null Mar 11 16:49:48.483: //33300/EB866A8480A6/CCAPI/cc_api_call_disconnect_done: Disposition=0, Interface=0x48675B98, Tag=0x0, Call Id=33300, Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0) Mar 11 16:49:48.483: //33300/EB866A8480A6/CCAPI/cc_api_call_disconnect_done: Call Disconnect Event Sent Mar 11 16:49:48.483: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:49:48.483: :cc_free_feature_vsa freeing 46FE0F30 Mar 11 16:49:48.483: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:49:48.483: vsacount in free is 0 ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR# Mar 11 16:50:18.236: //-1/108304C480A7/CCAPI/cc_api_display_ie_subfields: cc_api_call_setup_ind_common: cisco-username= ----- ccCallInfo IE subfields ----- cisco-ani=04917662032618 cisco-anitype=1 cisco-aniplan=1 cisco-anipi=0 cisco-anisi=3 dest=6445 cisco-desttype=2 cisco-destplan=1 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=-1 cisco-rdnplan=-1 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Mar 11 16:50:18.240: //-1/108304C480A7/CCAPI/cc_api_call_setup_ind_common: Interface=0x48675B98, Call Info( Calling Number=04917662032618,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Incoming Dial-peer=200, Progress Indication=NULL(0), Calling IE Present=TRUE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1 Mar 11 16:50:18.240: //-1/108304C480A7/CCAPI/ccCheckClipClir: In: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:50:18.240: //-1/108304C480A7/CCAPI/ccCheckClipClir: Out: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:50:18.240: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:18.240: :cc_get_feature_vsa malloc success Mar 11 16:50:18.240: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:18.240: cc_get_feature_vsa count is 1 Mar 11 16:50:18.240: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:18.240: :FEATURE_VSA attributes are: feature_name:0,fearture_time:1191055160,feature_id:33353 Mar 11 16:50:18.240: //33303/108304C480A7/CCAPI/cc_api_call_setup_ind_common: Set Up Event Sent; Call Info(Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN)) Mar 11 16:50:18.240: //33303/108304C480A7/CCAPI/cc_process_call_setup_ind: Event=0x46FEFE38 Mar 11 16:50:18.240: //33303/108304C480A7/CCAPI/ccCallSetContext: Context=0x459A17D4 Mar 11 16:50:18.240: //33303/108304C480A7/CCAPI/cc_process_call_setup_ind: >>>>CCAPI handed cid 33303 with tag 200 to app "_ManagedAppProcess_Default" Mar 11 16:50:18.244: //33303/108304C480A7/CCAPI/ccCallProceeding: Progress Indication=NULL(0) Mar 11 16:50:18.248: //33303/108304C480A7/CCAPI/ccCallSetupRequest: Destination=, Calling IE Present=TRUE, Mode=0, Outgoing Dial-peer=2000, Params=0x4599C1E4, Progress Indication=NULL(0) Mar 11 16:50:18.248: //33303/108304C480A7/CCAPI/ccCheckClipClir: In: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:50:18.248: //33303/108304C480A7/CCAPI/ccCheckClipClir: Out: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:50:18.248: //33303/108304C480A7/CCAPI/ccCallSetupRequest: Destination Pattern=6445, Called Number=6445, Digit Strip=FALSE Mar 11 16:50:18.248: //33303/108304C480A7/CCAPI/ccCallSetupRequest: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Redirect Number=, Display Info= Account Number=, Final Destination Flag=TRUE, Guid=108304C4-EEC2-11DC-80A7-001B0C63E550, Outgoing Dial-peer=2000 Mar 11 16:50:18.248: //33303/108304C480A7/CCAPI/cc_api_display_ie_subfields: ccCallSetupRequest: cisco-username= ----- ccCallInfo IE subfields ----- cisco-ani=04917662032618 cisco-anitype=1 cisco-aniplan=1 cisco-anipi=0 cisco-anisi=3 dest=6445 cisco-desttype=2 cisco-destplan=1 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=-1 cisco-rdnplan=-1 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Mar 11 16:50:18.248: //33303/108304C480A7/CCAPI/ccIFCallSetupRequestPrivate: Interface=0x46C1EC74, Interface Type=1, Destination=, Mode=0x0, Call Params(Calling Number=04917662032618,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=2000, Call Count On=FALSE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=) Mar 11 16:50:18.248: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:18.248: :cc_get_feature_vsa malloc success Mar 11 16:50:18.248: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:18.248: cc_get_feature_vsa count is 2 Mar 11 16:50:18.248: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:18.248: :FEATURE_VSA attributes are: feature_name:0,fearture_time:1191053864,feature_id:33354 Mar 11 16:50:18.248: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: callID=33304 Mar 11 16:50:18.248: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0 Mar 11 16:50:18.248: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0 Mar 11 16:50:18.248: //33304/108304C480A7/CCAPI/ccIFCallSetupRequestPrivate: SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1 Mar 11 16:50:18.248: //33304/108304C480A7/CCAPI/ccCallSetContext: Context=0x4599C194 Mar 11 16:50:18.248: //33303/108304C480A7/CCAPI/ccSaveDialpeerTag: Outgoing Dial-peer=2000 Mar 11 16:50:18.248: //-1/xxxxxxxxxxxx/H323/cch323_get_new_ccb: ccb (0x480CE850) is in use Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_call_setup: gw_id=1 Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_call_setup: Inserted ccb Mar 11 16:50:18.248: //-1/xxxxxxxxxxxx/H323/cch323_create_call_info_type_container: cch323_create_call_info_type_container: creating callInfoType container for callID = 33304 Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_get_caps_chn_info: No peer leg setup params Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_get_peer_info: Entry Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_get_peer_info: Have peer Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_get_peer_info: faxrate[41] proto[3] bitmask[10082] t38_inhibit[0] global_fax[1] t38fax[1] Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_set_pref_codec_list: Using Voice Class Codec, tag = 2 Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_set_pref_codec_list: First preferred codec(bytes)=5(160) Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_get_peer_info: Preferred codec set to G711_ULAW_64K with Bytes = 160 Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_get_peer_info: Flow Mode set to FLOW_THROUGH Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_get_peer_info: peer: 484CE9D0, peer->voice_peer_tag: 7D0, ccb: 480CE850 Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_set_h323_parms_from_dp: ccb h245addr bits = system[0x0007] Mar 11 16:50:18.248: //33304/108304C480A7/H323/cch323_set_h323_parms_from_dp: ccb ccm bits = system[0x0028] Mar 11 16:50:18.252: //33304/108304C480A7/H323/cch323_update_setup_callinfo: callingNumber = 04917662032618 Mar 11 16:50:18.252: //33304/108304C480A7/H323/cch323_update_setup_callinfo: called_oct3 = 0xA1, calling_oct3 = 0x11, calling_oct3a = 0x83 Mar 11 16:50:18.252: //33304/108304C480A7/H323/cch323_set_h323_control_options_outgoing: h245 sm mode = 271 Mar 11 16:50:18.252: //33304/108304C480A7/H323/cch323_set_h323_control_options_outgoing: h323_ctl=0x20 Mar 11 16:50:18.252: //33304/108304C480A7/H323/cch323_call_setup: No account/pin number available Mar 11 16:50:18.252: //33304/108304C480A7/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:50:18.252: //33304/108304C480A7/H323/cch323_call_setup_normal: Entry Mar 11 16:50:18.252: //33304/108304C480A7/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:50:18.256: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:18.256: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xB internal event to H225 SM Mar 11 16:50:18.256: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_SETUP while at state H225_IDLE Mar 11 16:50:18.256: //33304/108304C480A7/H323/check_qos_and_send_setup: Setup ccb 0x480CE850 Mar 11 16:50:18.256: //33304/108304C480A7/H323/cch323_rotary_validate: No peer_ccb available Mar 11 16:50:18.256: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xE internal event to H225 SM Mar 11 16:50:18.256: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_FS_SETUP while at state H225_IDLE Mar 11 16:50:18.256: //33304/108304C480A7/H323/idle_fsSetup_hdlr: Setup ccb 0x480CE850 Mar 11 16:50:18.256: //33304/108304C480A7/H323/idle_fsSetup_hdlr: send_fastStart_setup called Mar 11 16:50:18.256: //33304/108304C480A7/H323/send_fastStart_setup: Entry Mar 11 16:50:18.256: //33304/108304C480A7/H323/cch323_build_local_encoded_fastStartOLCs: state_mc_mode=0x10F on outbound leg Mar 11 16:50:18.256: //33304/108304C480A7/H323/cch323_build_local_encoded_fastStartOLCs: srcAddress = 0xA160302, h245_lport = 0, flow mode = 1, minimum_qos=0 Mar 11 16:50:18.256: //33304/108304C480A7/H323/h245_set_local_audio_mask: Near-end Pref Codecs = G711_ULAW_64K Mar 11 16:50:18.256: //33304/108304C480A7/H323/cch323_generic_open_logical_channel: current codec = 5:160:160 Mar 11 16:50:18.256: //33304/108304C480A7/H323/cch323_generic_open_logical_channel: Codec is G711_ULAW_64K Mar 11 16:50:18.256: //33304/108304C480A7/H323/cch323_generic_open_logical_channel: Filling in qosCapability field to 0 Mar 11 16:50:18.260: //33304/108304C480A7/H323/generic_send_setup: Entry Mar 11 16:50:18.260: //33304/108304C480A7/H323/generic_send_setup: generic_send_setup: is_overlap = 0, info_complete = 0 Mar 11 16:50:18.260: //33304/108304C480A7/H323/generic_send_setup: sending calling IE Mar 11 16:50:18.260: //33304/108304C480A7/H323/generic_send_setup: ====== PI = 0 Mar 11 16:50:18.260: //33304/108304C480A7/H323/generic_send_setup: Send infoXCap=144, infoXRate=16, rateMult=0, xMode=128, info_layer1_prot=163 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_h225_copy_send_rawMsg: Copy raw message data to nonStdInfo Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_h225_copy_send_rawMsg: Copy tunnelled GTD/ISUP content Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: (for cch323_h225_copy_send_rawMsg): raw message is 231 bytes: Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 04 03 80 90 A3 18 03 A1 83 81 6C 0F 11 83 34 39 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 31 37 36 36 32 30 33 32 36 31 38 70 0A A1 32 30 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 37 31 35 30 32 34 35 A1 1C BD 9E 81 00 03 67 74 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 64 00 00 00 B2 49 41 4D 2C 0D 0A 50 52 4E 2C 69 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 73 64 6E 2A 2C 2C 41 54 54 34 2A 2C 0D 0A 55 53 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 49 2C 72 61 74 65 2C 63 2C 73 2C 63 2C 31 0D 0A Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 55 53 49 2C 6C 61 79 31 2C 61 6C 61 77 0D 0A 54 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 4D 52 2C 30 30 0D 0A 43 50 4E 2C 30 34 2C 2C 31 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 2C 32 30 37 31 35 30 32 34 35 0D 0A 43 47 4E 2C Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 30 36 2C 2C 31 2C 79 2C 34 2C 34 39 31 37 36 36 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 32 30 33 32 36 31 38 0D 0A 43 50 43 2C 30 39 0D Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 0A 46 43 49 2C 2C 2C 2C 2C 2C 2C 79 2C 0D 0A 47 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 43 49 2C 31 30 38 33 30 34 63 34 65 65 63 32 31 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 31 64 63 38 30 61 37 30 30 31 62 30 63 36 33 65 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_prnt_rawmsg: 35 35 30 0D 0A 0D 0A Mar 11 16:50:18.260: //33304/108304C480A7/H323/generic_send_setup: src address = 10.22.3.2; dest address = 10.22.1.18 Mar 11 16:50:18.260: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:50:18.260: //33304/108304C480A7/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_REQ_FS_SETUP state Mar 11 16:50:18.260: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 IWF SM Mar 11 16:50:18.260: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_FASTSTART while at state IWF_IDLE Mar 11 16:50:18.260: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:18.360: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:50:18.360: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:50:18.360: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:50:18.360: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: Retry, fd=2 Mar 11 16:50:18.460: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:50:18.460: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:50:18.460: //-1/xxxxxxxxxxxx/H323/h323_gw_stop_sock_blocked_timer: fd 2 Mar 11 16:50:18.460: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:18.460: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x47FFEA18, len=80, msgPtr=0x47FFCF68 Mar 11 16:50:18.460: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225 Mar 11 16:50:18.460: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type ALERTIND_CHOSEN Mar 11 16:50:18.464: //33304/108304C480A7/H323/alert_ind: ====== PI = 0 Mar 11 16:50:18.464: //33304/108304C480A7/H323/alert_ind: alert ind ie_bit_mask 0x1260, displayInfo Mar 11 16:50:18.464: //33304/108304C480A7/H323/alert_ind: delay H245 address in alert Mar 11 16:50:18.464: //33304/108304C480A7/H323/cch323_h225_receiver: ALERTIND_CHOSEN: src address = 10.22.3.2; dest address = 10.22.1.18 Mar 11 16:50:18.464: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_ALERT_IND while at state H225_REQ_FS_SETUP Mar 11 16:50:18.464: //33304/108304C480A7/H323/cch323_get_embedded_obj_from_ccb: ccb=0x480CE850, tag=18, size=83 Mar 11 16:50:18.464: //33304/108304C480A7/H323/cch323_get_embedded_obj_from_ccb: Extraction FAILED Mar 11 16:50:18.464: //33304/108304C480A7/CCAPI/cc_api_set_delay_xport: CallInfo(delay xport=TRUE) Mar 11 16:50:18.464: //33304/108304C480A7/CCAPI/cc_api_call_alert: Interface=0x46C1EC74, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1) Mar 11 16:50:18.464: //33304/108304C480A7/CCAPI/cc_api_call_alert: Call Entry(Retry Count=0, Responsed=TRUE) Mar 11 16:50:18.464: //33304/108304C480A7/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_SETUP state to H225_REQ_FS_ALERT state Mar 11 16:50:18.464: //33303/108304C480A7/CCAPI/ccCallAlert: Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1) Mar 11 16:50:18.464: //33303/108304C480A7/CCAPI/ccCallAlert: Call Entry(Responsed=TRUE, AlertSent=TRUE) Mar 11 16:50:18.464: //33303/108304C480A7/CCAPI/ccGenerateToneInfo: Stop Tone On Digit=FALSE, Tone=Ring Back, Tone Direction=Network, Params=0x0, Call Id=33303 Mar 11 16:50:18.712: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:18.712: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x47FFEA18, len=131, msgPtr=0x47D7C2C4 Mar 11 16:50:18.712: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225 Mar 11 16:50:18.712: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type PROGRESSIND_CHOSEN Mar 11 16:50:18.712: //33304/108304C480A7/H323/progress_ind: ======= PI = 1 cause 0 Mar 11 16:50:18.712: //33304/108304C480A7/H323/cch323_h225_receiver: PROGRESSIND_CHOSEN: src address = 10.22.3.2; dest address = 10.22.1.18 Mar 11 16:50:18.712: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_FS_PROGRESS_IND while at state H225_REQ_FS_ALERT Mar 11 16:50:18.712: //33304/108304C480A7/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_ALERT state to H225_ACC_FS_ALERT state Mar 11 16:50:18.712: //33304/108304C480A7/H323/cch323_selectFastStart_codecs: Codec: loc(5), rem(5); Bytes: loc(160), Fwd(160), Rev(160) Mar 11 16:50:18.712: //33304/108304C480A7/H323/cch323_receive_fastStart_cap_response: Send cap ind to peer leg Mar 11 16:50:18.712: //33304/108304C480A7/H323/cch323_build_olc_for_ccapi: audioFastStartArray=0x465784B0 Mar 11 16:50:18.712: //33304/108304C480A7/H323/cch323_build_olc_for_ccapi: channel_info ptr=0x47FE0630, ccb ptr=0x480CE850 Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_build_olc_for_ccapi: Channel Information: Logical Channel Number (fwd): 1 Logical Channel Number (rev): 129 Channel address (fwd/rev): 0xA160112 RTP Channel (fwd/rev): 56004 RTCP Channel (fwd/rev): 56005 QoS Capability (fwd/rev): 0 Symmetric Audio Codec: 5 Symmetric Audio Codec Bytes: 160 Flow Mode: 0 Silence Suppression: 1 Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_build_olc_for_ccapi: NumOfElements = 1 idx = 1 Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_do_cap_ind: Registry cap_ind is not done Mar 11 16:50:18.716: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_FASTSTART while at state IWF_IDLE Mar 11 16:50:18.716: //33304/108304C480A7/H323/h245_iwf_set_new_state: changing from IWF_OLC_IDLE state to IWF_OLC_DONE state Mar 11 16:50:18.716: //33304/108304C480A7/H323/fastStartIdle: H245_EV_OLC_IN/OUT_DONE sent to olc Mar 11 16:50:18.716: //33304/108304C480A7/H323/h245_olc_in_sm: Received H245_EV_OLC_IN_DONE while at state H245_OLC_IN_STATE_IDLE Mar 11 16:50:18.716: //33304/108304C480A7/H323/h245_olc_in_set_new_state: Changing from H245_OLC_IN_STATE_IDLE state to H245_OLC_IN_STATE_ESTABLISHED state Mar 11 16:50:18.716: //33304/108304C480A7/H323/h245_olc_out_sm: Received H245_EV_OLC_OUT_DONE while at state H245_OLC_OUT_STATE_IDLE Mar 11 16:50:18.716: //33304/108304C480A7/H323/h245_olc_out_set_new_state: Changing from H245_OLC_OUT_STATE_IDLE state to H245_OLC_OUT_STATE_ESTABLISHED state Mar 11 16:50:18.716: //33304/108304C480A7/H323/h323_open_rtp_stream: Media In-active notification object not attached to ccb Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_set_dtmf_iw_enabled: negotiated dtmf relay: 0, dtmf_iw_enabled: 0, dtmf_sccp_enabled: 0 Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_rtp_open_notify: Entry Mar 11 16:50:18.716: //33304/108304C480A7/H323/generic_cut_progress_notify: ====== PI = 1, cause = 0 Mar 11 16:50:18.716: //33304/108304C480A7/CCAPI/cc_api_call_cut_progress: Interface=0x46C1EC74, Progress Indication=NOT END TO END ISDN(1), Signal Indication=SIGNAL RINGBACK(1), Cause Value=0 Mar 11 16:50:18.716: //33304/108304C480A7/CCAPI/cc_api_call_cut_progress: Call Entry(Responsed=TRUE) Mar 11 16:50:18.716: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x16 internal event to H225 SM Mar 11 16:50:18.716: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_FACIL_SWITCH_H245 while at state H225_ACC_FS_ALERT Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_LISTEN_REQ_EVENT Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_h245_connection_sm: state=0, event=0, ccb=480CE850, listen state=0 Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_h245_connection_sm: H245_LISTEN: Received event H245_LISTEN_REQ_EVENT while at H245_NONE state Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_h245_set_new_state: Changing from H245_NONE state to H245_WAITING state Mar 11 16:50:18.716: //33304/108304C480A7/H323/cch323_h225_set_new_state: Changing from H225_ACC_FS_ALERT state to H225_ALERT state Mar 11 16:50:18.716: //33303/108304C480A7/CCAPI/ccCallCutProgress: Progress Indication=NOT END TO END ISDN(1), Signal Indication=SIGNAL RINGBACK(1), Cause Value=0 Voice Call Send Alert=FALSE, Call Entry(AlertSent=TRUE) Mar 11 16:50:18.716: //33303/108304C480A7/CCAPI/ccCallCutProgress: Call Entry(Responsed=TRUE) Mar 11 16:50:18.720: //33303/108304C480A7/CCAPI/ccGenerateToneInfo: Stop Tone On Digit=FALSE, Tone=Null, Tone Direction=Network, Params=0x0, Call Id=33303 Mar 11 16:50:18.720: //33303/xxxxxxxxxxxx/CCAPI/ccConferenceCreate: (confID=0x473F9400, callID1=0x8217, callID2=0x8218, tag=0x0) Mar 11 16:50:18.720: //33303/108304C480A7/CCAPI/ccConferenceCreate: Conference Id=0x473F9400, Call Id1=33303, Call Id2=33304, Tag=0x0 Mar 11 16:50:18.720: //33303/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done: Conference Id=0x4089, Source Interface=0x48675B98, Source Call Id=33303, Destination Call Id=33304, Disposition=0x0, Tag=0xFFFFFFFF Mar 11 16:50:18.720: //33304/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream: Mar 11 16:50:18.720: cc_api_get_xcode_stream : 4368 Mar 11 16:50:18.720: //33304/xxxxxxxxxxxx/CCAPI/cc_api_bridge_done: Conference Id=0x4089, Source Interface=0x46C1EC74, Source Call Id=33304, Destination Call Id=33303, Disposition=0x0, Tag=0x0 Mar 11 16:50:18.720: //33303/108304C480A7/CCAPI/cc_generic_bridge_done: Conference Id=0x4089, Source Interface=0x46C1EC74, Source Call Id=33304, Destination Call Id=33303, Disposition=0x0, Tag=0x0 Mar 11 16:50:18.720: //33303/108304C480A7/CCAPI/ccConferenceCreate: Call Entry(Conference Id=0x4089, Destination Call Id=33304) Mar 11 16:50:18.720: //33304/108304C480A7/CCAPI/ccConferenceCreate: Call Entry(Conference Id=0x4089, Destination Call Id=33303) Mar 11 16:50:18.720: //33303/108304C480A7/CCAPI/cc_api_caps_ind: Destination Interface=0x46C1EC74, Destination Call Id=33304, Source Call Id=33303, Caps(Codec=0x1, Fax Rate=0x1, Vad=0x1, Modem=0x2, Codec Bytes=20, Signal Type=3) Mar 11 16:50:18.720: //33303/108304C480A7/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=250(ms), Fax Nom=300(ms)) Mar 11 16:50:18.720: //-1/xxxxxxxxxxxx/H323/cch323_post_caps_ind: callID=33304, ExtendedCaps not present Mar 11 16:50:18.720: //33303/108304C480A7/CCAPI/cc_process_notify_bridge_done: Conference Id=0x4089, Call Id1=33303, Call Id2=33304 Mar 11 16:50:18.724: //33304/108304C480A7/H323/cch323_set_dtmf_iw_enabled: negotiated dtmf relay: 0, dtmf_iw_enabled: 0, dtmf_sccp_enabled: 0 Mar 11 16:50:18.724: //33304/108304C480A7/H323/cch323_rtp_open_notify: Entry Mar 11 16:50:18.724: //33304/108304C480A7/H323/cch323_caps_ind: gw_id=1 Mar 11 16:50:18.724: //33304/108304C480A7/H323/cch323_peer_caps_ind_common: Load DSP with Negotiated (No DP match) codec(5) g711ulaw, Bytes=160 Mar 11 16:50:18.724: //33304/108304C480A7/H323/cch323_peer_caps_ind_common: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE Mar 11 16:50:18.724: //33304/108304C480A7/H323/cch323_peer_caps_ind_common: cap_modem_proto: 0, cap_modem_codec: 0, cap_modem_redundancy: 0, payload: 100, modem_relay: 0, gw_xid: 1 gw_controlled=0 Mar 11 16:50:18.724: //33304/108304C480A7/CCAPI/cc_api_caps_ind: Destination Interface=0x48675B98, Destination Call Id=33303, Source Call Id=33304, Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1, Modem=0x0, Codec Bytes=160, Signal Type=2) Mar 11 16:50:18.724: //33304/108304C480A7/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=250(ms), Fax Nom=300(ms)) Mar 11 16:50:18.724: //33304/108304C480A7/CCAPI/cc_api_caps_ack: Destination Interface=0x48675B98, Destination Call Id=33303, Source Call Id=33304, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=4984) Mar 11 16:50:18.724: //33303/108304C480A7/CCAPI/cc_api_caps_ack: Destination Interface=0x46C1EC74, Destination Call Id=33304, Source Call Id=33303, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=4984) Mar 11 16:50:18.728: //33303/108304C480A7/CCAPI/cc_api_voice_mode_event: Call Id=33303 Mar 11 16:50:18.728: //33303/108304C480A7/CCAPI/cc_api_voice_mode_event: Call Entry(Context=0x459A17D4) Mar 11 16:50:18.728: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 3 Event 0x1 Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_h245_channel_established_ind: Using fd=4 to send msgs Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_ESTABLISHED_EVENT Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_h245_connection_sm: state=1, event=2, ccb=480CE850, listen state=1 Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_h245_connection_sm: H245_LISTEN: Received event H245_ESTABLISHED_EVENT while at H245_WAITING state Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_h245_set_new_state: Changing from H245_WAITING state to H245_CONNECTED state Mar 11 16:50:18.728: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x2 internal event to H245 IWF SM Mar 11 16:50:18.728: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_H245_CONNECTED while at state IWF_IDLE Mar 11 16:50:18.728: //33304/108304C480A7/H323/h245_iwf_set_new_state: changing from IWF_IDLE state to IWF_H245_CONNECTED state Mar 11 16:50:18.728: //33304/108304C480A7/H323/h245_iwf_set_new_state: changing from IWF_H245_CONNECTED state to IWF_AWAIT_CAP_MSD_RESP state Mar 11 16:50:18.728: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 CAP OUT SM Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_run_h245_cap_out_sm: Received H245_EVENT_CAP_REQ while at state IDLE Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: cch323_send_cap_request: ccb->callID: 33304, ccb->h245.state_mc_mode: 271 Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: Second try for videocaps Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: ccb->callID: 33304, video_cap_mask: 0x0 Mar 11 16:50:18.728: //33304/108304C480A7/H323/h245_send_generic_audio_caps: Using DP configured codecs Mar 11 16:50:18.728: //33304/108304C480A7/H323/h245_normalize_preferred_codec_list: Near-end Pref Codecs = G711_ULAW_64K Mar 11 16:50:18.728: //33304/108304C480A7/H323/h245_send_generic_audio_caps: [reg]audio mask after operation=0x1 Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: Included rtp in caps table Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: Included t38 fax in caps table Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: Included signal in caps table Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: Included alpha in caps table Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: Included hookflash in caps table Mar 11 16:50:18.728: //33304/108304C480A7/H323/cch323_send_cap_request: Included rtp-nte in caps table Mar 11 16:50:18.732: //33304/108304C480A7/H323/h245_cap_out_set_new_state: changing from IDLE state to AWAITING_RESPONSE state Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 MS SM Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_run_h245_ms_sm: Received event H245_EVENT_MSD while at state H245_MS_NONE Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_run_h245_ms_sm: Sent MSD Request Mar 11 16:50:18.732: //33304/108304C480A7/H323/h245_ms_set_new_state: Changing from H245_MS_NONE state to H245_MS_OUTGOING_WAIT state Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=59, msgPtr=0x48675E38 Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_h245_cap_ind: Masks au=0x3 data=0x4 uinp=0x0 Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_run_h245_cap_in_sm: Received H245_EVENT_CAP_IND while at state IDLE Mar 11 16:50:18.732: //33304/108304C480A7/H323/h245_cap_in_set_new_state: changing from IDLE state to AWAITING_RESPONSE state Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x4 internal event to H245 IWF SM Mar 11 16:50:18.732: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_CAP_IND while at state IWF_AWAIT_CAP_MSD_RESP Mar 11 16:50:18.732: //33304/108304C480A7/H323/h323_validate_cap_ind: Remote Pref Codecs UnOrdered (0x3) = [G711_ULAW_64K] [G711_ALAW_64K] [] Mar 11 16:50:18.732: //33304/108304C480A7/H323/h245_handle_cap_ind: TCS received from remote end. Setting h245 status flag H245_CAP_REQUEST_RCVD Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 CAP IN SM Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_run_h245_cap_in_sm: Received H245_EVENT_CAP_RESP while at state AWAITING_RESPONSE Mar 11 16:50:18.732: //33304/108304C480A7/H323/h245_cap_in_set_new_state: changing from AWAITING_RESPONSE state to IDLE state Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=7, msgPtr=0x465D36D4 Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_run_h245_ms_sm: Received event H245_EVENT_MS_IND while at state H245_MS_OUTGOING_WAIT Mar 11 16:50:18.732: //33304/108304C480A7/H323/MSDetermination: rtt=50 rsdnum=5806220, ltt=60 lsdnum=4524 Mar 11 16:50:18.732: //33304/108304C480A7/H323/MSDetermination: Am MASTER, ccb->h245.h245_mdStatus = 0x1 Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_run_h245_ms_sm: MS_Determine_indication to Appl: Sent MSD ACK! Mar 11 16:50:18.732: //33304/108304C480A7/H323/h245_ms_set_new_state: Changing from H245_MS_OUTGOING_WAIT state to H245_MS_INCOMING_WAIT state Mar 11 16:50:18.732: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x10 internal event to H245 IWF SM Mar 11 16:50:18.732: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_MSD_ACK_SENT while at state IWF_AWAIT_CAP_MSD_RESP Mar 11 16:50:18.732: //33304/108304C480A7/H323/h323_find_negotiated_codec: Audio Mask 0x3, Negotiated Codec G711_ULAW_64K(5) Codec Bytes 160 Mar 11 16:50:18.732: //33304/108304C480A7/H323/h323_find_negotiated_dtmf: peer_data_cap_mask=0x4, peer_user_input_cap_mask=0x0 Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_set_dtmf_iw_enabled: negotiated dtmf relay: 3, dtmf_iw_enabled: 0, dtmf_sccp_enabled: 0 Mar 11 16:50:18.732: //33304/108304C480A7/H323/h323_find_negotiated_dtmf: Negotiated DTMF relay - 0x3 Mar 11 16:50:18.732: //33304/108304C480A7/H323/h245_iwf_common_msdacksent: Negotiated codecs and dtmf are initialised in ccb Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_peer_caps_ack: Sending caps resp event to CAP sm Mar 11 16:50:18.732: //33304/108304C480A7/H323/cch323_peer_caps_ack: ccb not interested in caps_ack primitive Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=3, msgPtr=0x465D36D4 Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_run_h245_cap_out_sm: Received H245_EVENT_CAP_CFM while at state AWAITING_RESPONSE Mar 11 16:50:18.736: //33304/108304C480A7/H323/h245_cap_out_set_new_state: changing from AWAITING_RESPONSE state to IDLE state Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x5 internal event to H245 IWF SM Mar 11 16:50:18.736: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_CAP_CFM while at state IWF_AWAIT_CAP_MSD_RESP Mar 11 16:50:18.736: //33304/108304C480A7/H323/h245_iwf_set_new_state: changing from IWF_AWAIT_CAP_MSD_RESP state to IWF_AWAIT_MSD_RESP state Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=2, msgPtr=0x465D36D4 Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_run_h245_ms_sm: Received event H245_EVENT_MS_CFM while at state H245_MS_INCOMING_WAIT Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_run_h245_ms_sm: Local Status = 0x1, Remote Status = 0x1 Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_run_h245_ms_sm: MSD Determine CFM to APPL, both sides agree! Mar 11 16:50:18.736: //33304/108304C480A7/H323/h245_ms_set_new_state: Changing from H245_MS_INCOMING_WAIT state to H245_MS_NONE state Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x7 internal event to H245 IWF SM Mar 11 16:50:18.736: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_MSD_CFM while at state IWF_AWAIT_MSD_RESP Mar 11 16:50:18.736: //33304/108304C480A7/H323/h245_iwf_handle_init_olc: Turning off h245 status flag H245_MSD_ACK_SENT_CODEC_INIT_DONE Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: Load codec(5) g711ulaw, codec_bytes = 160 Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: cap_modem_proto: 0, cap_modem_codec: 0, cap_modem_redundancy: 0, modem_relay: 0, gw_xid: 0 gw_controlled: 0 Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: Negotiated dtmf relay is alpha Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: Sending caps to the other leg, context = 474863A0 Mar 11 16:50:18.736: //33304/108304C480A7/CCAPI/cc_api_caps_ind: Destination Interface=0x48675B98, Destination Call Id=33303, Source Call Id=33304, Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1, Modem=0x0, Codec Bytes=160, Signal Type=2) Mar 11 16:50:18.736: //33304/108304C480A7/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=250(ms), Fax Nom=300(ms)) Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: Sending caps_ack because NTFY DSP set Mar 11 16:50:18.736: //33304/108304C480A7/CCAPI/cc_api_caps_ack: Destination Interface=0x48675B98, Destination Call Id=33303, Source Call Id=33304, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=4984) Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: Load codec(5) g711ulaw, codec_bytes = 160 Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: cap_modem_proto: 0, cap_modem_codec: 0, cap_modem_redundancy: 0, modem_relay: 0, gw_xid: 0 gw_controlled: 0 Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: Negotiated dtmf relay is alpha Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: Sending caps to the other leg, context = 474863A0 Mar 11 16:50:18.736: //33304/108304C480A7/CCAPI/cc_api_caps_ind: Destination Interface=0x48675B98, Destination Call Id=33303, Source Call Id=33304, Caps(Codec=0x1, Fax Rate=0x2, Vad=0x1, Modem=0x0, Codec Bytes=160, Signal Type=2) Mar 11 16:50:18.736: //33304/108304C480A7/CCAPI/cc_api_caps_ind: Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms), Playout Max=250(ms), Fax Nom=300(ms)) Mar 11 16:50:18.736: //33304/108304C480A7/H323/cch323_do_cap_ind: Sending caps_ack because NTFY DSP set Mar 11 16:50:18.736: //33304/108304C480A7/CCAPI/cc_api_caps_ack: Destination Interface=0x48675B98, Destination Call Id=33303, Source Call Id=33304, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=4984) Mar 11 16:50:18.736: //33304/108304C480A7/H323/h245_iwf_set_new_state: changing from IWF_AWAIT_MSD_RESP state to IWF_ACTIVE state Mar 11 16:50:18.736: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x19 internal event to H225 SM Mar 11 16:50:18.736: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_H245_SUCCESS while at state H225_ALERT Mar 11 16:50:18.736: //33304/108304C480A7/H323/default_no_action_hdlr: Ignored H225_EV_H245_SUCCESS event in H225_ALERT state Mar 11 16:50:18.740: //33303/108304C480A7/CCAPI/cc_api_caps_ack: Destination Interface=0x46C1EC74, Destination Call Id=33304, Source Call Id=33303, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=4984) Mar 11 16:50:18.740: //33303/108304C480A7/CCAPI/cc_api_caps_ack: Destination Interface=0x46C1EC74, Destination Call Id=33304, Source Call Id=33303, Caps(Codec=g711ulaw(0x1), Fax Rate=FAX_RATE_VOICE(0x2), Vad=OFF(0x1), Modem=OFF(0x0), Codec Bytes=160, Signal Type=2, Seq Num Start=4984) Mar 11 16:50:18.740: //33303/108304C480A7/CCAPI/cc_api_voice_mode_event: Call Id=33303 Mar 11 16:50:18.740: //33303/108304C480A7/CCAPI/cc_api_voice_mode_event: Call Entry(Context=0x459A17D4) Mar 11 16:50:18.740: //33303/108304C480A7/CCAPI/cc_api_voice_mode_event: Call Id=33303 Mar 11 16:50:18.740: //33303/108304C480A7/CCAPI/cc_api_voice_mode_event: Call Entry(Context=0x459A17D4) Mar 11 16:50:18.740: //33304/108304C480A7/H323/cch323_peer_caps_ack: Sending caps resp event to CAP sm Mar 11 16:50:18.740: //33304/108304C480A7/H323/cch323_peer_caps_ack: ccb not interested in caps_ack primitive Mar 11 16:50:18.740: //33304/108304C480A7/H323/cch323_peer_caps_ack: Sending caps resp event to CAP sm Mar 11 16:50:18.740: //33304/108304C480A7/H323/cch323_peer_caps_ack: ccb not interested in caps_ack primitive Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x47FFEA18, len=50, msgPtr=0x48675E38 Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225 Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type RELEASEIND_CHOSEN Mar 11 16:50:49.712: //33304/108304C480A7/H323/release_ind: Disconnect cause 0 location code 0 Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/h323_set_release_source_for_peer: ownCallId[33304], src[4] Mar 11 16:50:49.712: //33304/108304C480A7/H323/cch323_h225_receiver: RELEASEIND_CHOSEN: src address = 10.22.3.2; dest address = 10.22.1.18 Mar 11 16:50:49.712: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_RELEASE_IND while at state H225_ALERT Mar 11 16:50:49.712: //33304/108304C480A7/H323/cch323_traverse_enum_contact_list: State = 3 Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/h323_set_cc_cause_for_spi_err: Categorized cause:127, category:127 Mar 11 16:50:49.712: //33304/108304C480A7/CCAPI/cc_api_call_disconnected: Cause Value=127, Interface=0x46C1EC74, Call Id=33304 Mar 11 16:50:49.712: //33304/108304C480A7/CCAPI/cc_api_call_disconnected: Call Entry(Responsed=TRUE, Cause Value=127, Retry Count=0) Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=8, msgPtr=0x465D36D4 Mar 11 16:50:49.712: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:50:49.716: //33304/108304C480A7/H323/h245_olc_in_sm: Received H245_EV_OLC_CLC_IND while at state H245_OLC_IN_STATE_ESTABLISHED Mar 11 16:50:49.716: //33304/108304C480A7/H323/h245_olc_in_set_new_state: Changing from H245_OLC_IN_STATE_ESTABLISHED state to H245_OLC_IN_STATE_IDLE state Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x1B internal event to H245 IWF SM Mar 11 16:50:49.716: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_CLC_IND while at state IWF_OLC_DONE Mar 11 16:50:49.716: //33304/108304C480A7/H323/h245_iwf_set_new_state: changing from IWF_OLC_DONE state to IWF_OLC_OUT_DONE state Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 2 Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/cch323_cleanup_xport: hashDestroy for TcpFDTbl Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x2D internal event to H225 SM Mar 11 16:50:49.716: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_CONN_LOST while at state H225_ALERT Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x480CE850, len=2, msgPtr=0x465D3E3C Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.245 Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 4 Event 0x1 Mar 11 16:50:49.716: //33304/108304C480A7/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_DISCONNECT_EVENT Mar 11 16:50:49.716: //33304/108304C480A7/H323/cch323_h245_connection_sm: state=0, event=4, ccb=480CE850, listen state=2 Mar 11 16:50:49.716: //33304/108304C480A7/H323/cch323_h245_connection_sm: H245_CONNECT: Received event H245_DISCONNECT_EVENT while at H245_NONE state Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 4 Mar 11 16:50:49.716: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 3 Mar 11 16:50:49.716: //33304/108304C480A7/H323/cch323_gw_process_read_socket: cch323_gw_process_read_socket: H.245 socket error, ccb status = 402924554, call release = 0, call disconnected = 1, fd = 4, rc = 4 Mar 11 16:50:49.716: //33303/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources: release reserved xcoding resource. Mar 11 16:50:49.716: //33304/108304C480A7/CCAPI/ccCallSetAAA_Accounting: Accounting=1, Call Id=33304 Mar 11 16:50:49.716: //33303/108304C480A7/CCAPI/ccConferenceDestroy: Conference Id=0x4089, Tag=0x0 Mar 11 16:50:49.720: //33303/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done: Conference Id=0x4089, Source Interface=0x48675B98, Source Call Id=33303, Destination Call Id=33304, Disposition=0x0, Tag=0x0 Mar 11 16:50:49.720: //33304/xxxxxxxxxxxx/CCAPI/cc_api_bridge_drop_done: Conference Id=0x4089, Source Interface=0x46C1EC74, Source Call Id=33304, Destination Call Id=33303, Disposition=0x0, Tag=0x0 Mar 11 16:50:49.720: //33303/108304C480A7/CCAPI/cc_generic_bridge_done: Conference Id=0x4089, Source Interface=0x46C1EC74, Source Call Id=33304, Destination Call Id=33303, Disposition=0x0, Tag=0x0 Mar 11 16:50:49.720: //33304/108304C480A7/CCAPI/ccCallDisconnect: Cause Value=127, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=127) Mar 11 16:50:49.720: //33304/108304C480A7/CCAPI/ccCallDisconnect: Cause Value=127, Call Entry(Responsed=TRUE, Cause Value=127) Mar 11 16:50:49.720: //33304/108304C480A7/CCAPI/cc_api_get_transfer_info: Transfer Number Is Null Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_do_call_disconnect: gw_id=1, discCause=127 Mar 11 16:50:49.720: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x9 internal event to H225 SM Mar 11 16:50:49.720: //33304/108304C480A7/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_ALERT Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_h225_set_new_state: Changing from H225_ALERT state to H225_IDLE state Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_call_generic_cleanup: Disconnected flag 1 Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_store_call_history_entry: Trying to store call history/remove call_info while RTP session exists Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_store_call_history_entry: Call Active Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_store_call_history_entry: Call History Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:50:49.720: //33304/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_H245_DISCONN while at state IWF_ACTIVE Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_send_event_to_h245_connection_sm: Changing to new event H245_DISCONNECT_EVENT Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_h245_connection_sm: state=0, event=4, ccb=480CE850, listen state=0 Mar 11 16:50:49.720: //33304/108304C480A7/H323/cch323_h245_connection_sm: H245_CONNECT: Received event H245_DISCONNECT_EVENT while at H245_NONE state Mar 11 16:50:49.720: //33304/108304C480A7/H323/h245_iwf_set_new_state: changing from IWF_ACTIVE state to IWF_IDLE state Mar 11 16:50:49.720: //33304/108304C480A7/CCAPI/cc_api_call_disconnect_done: Disposition=0, Interface=0x46C1EC74, Tag=0x0, Call Id=33304, Call Entry(Disconnect Cause=127, Voice Class Cause Code=0, Retry Count=0) Mar 11 16:50:49.724: //33304/108304C480A7/CCAPI/cc_api_call_disconnect_done: Call Disconnect Event Sent Mar 11 16:50:49.724: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:50:49.724: :cc_free_feature_vsa freeing 46FE0A20 Mar 11 16:50:49.724: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:50:49.724: vsacount in free is 1 Mar 11 16:50:49.724: //-1/xxxxxxxxxxxx/H323/cch323_call_generic_cleanup: Freeing ccb (0x480CE850) Mar 11 16:50:49.728: //33303/108304C480A7/CCAPI/ccCallSetupRequest: Destination=, Calling IE Present=TRUE, Mode=0, Outgoing Dial-peer=1017, Params=0x45998864, Progress Indication=NULL(0) Mar 11 16:50:49.728: //33303/108304C480A7/CCAPI/ccCheckClipClir: In: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:50:49.728: //33303/108304C480A7/CCAPI/ccCheckClipClir: Out: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed) Mar 11 16:50:49.728: //33303/108304C480A7/CCAPI/ccCallSetupRequest: Destination Pattern=64.., Called Number=6445, Digit Strip=FALSE Mar 11 16:50:49.728: //33303/108304C480A7/CCAPI/ccCallSetupRequest: Calling Number=04917662032618(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Redirect Number=, Display Info= Account Number=, Final Destination Flag=TRUE, Guid=108304C4-EEC2-11DC-80A7-001B0C63E550, Outgoing Dial-peer=1017 Mar 11 16:50:49.728: //33303/108304C480A7/CCAPI/cc_api_display_ie_subfields: ccCallSetupRequest: cisco-username= ----- ccCallInfo IE subfields ----- cisco-ani=04917662032618 cisco-anitype=1 cisco-aniplan=1 cisco-anipi=0 cisco-anisi=3 dest=6445 cisco-desttype=2 cisco-destplan=1 cisco-rdie=FFFFFFFF cisco-rdn= cisco-rdntype=-1 cisco-rdnplan=-1 cisco-rdnpi=-1 cisco-rdnsi=-1 cisco-redirectreason=-1 fwd_final_type =0 final_redirectNumber = hunt_group_timeout =0 Mar 11 16:50:49.728: //33303/108304C480A7/CCAPI/ccIFCallSetupRequestPrivate: Interface=0x46C1EC74, Interface Type=1, Destination=, Mode=0x0, Call Params(Calling Number=04917662032618,(Calling Name=)(TON=International, NPI=ISDN, Screening=Network, Presentation=Allowed), Called Number=6445(TON=National, NPI=ISDN), Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=1017, Call Count On=FALSE, Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=) Mar 11 16:50:49.728: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:49.728: :cc_get_feature_vsa malloc success Mar 11 16:50:49.728: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:49.728: cc_get_feature_vsa count is 2 Mar 11 16:50:49.728: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa: Mar 11 16:50:49.728: :FEATURE_VSA attributes are: feature_name:0,fearture_time:1191053864,feature_id:33355 Mar 11 16:50:49.728: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: callID=33305 Mar 11 16:50:49.728: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0 Mar 11 16:50:49.728: //-1/xxxxxxxxxxxx/H323/cch323_post_call_setup_request: incoming_call=0 incoming_media=0 Mar 11 16:50:49.728: //33305/108304C480A7/CCAPI/ccIFCallSetupRequestPrivate: SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1 Mar 11 16:50:49.728: //33305/108304C480A7/CCAPI/ccCallSetContext: Context=0x45998814 Mar 11 16:50:49.728: //33303/108304C480A7/CCAPI/ccSaveDialpeerTag: Outgoing Dial-peer=1017 Mar 11 16:50:49.732: //-1/xxxxxxxxxxxx/H323/cch323_get_new_ccb: ccb (0x480CE850) is in use Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_call_setup: gw_id=1 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_call_setup: Inserted ccb Mar 11 16:50:49.732: //-1/xxxxxxxxxxxx/H323/cch323_create_call_info_type_container: cch323_create_call_info_type_container: creating callInfoType container for callID = 33305 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_get_caps_chn_info: No peer leg setup params Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_get_peer_info: Entry Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_get_peer_info: Have peer Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_get_peer_info: faxrate[41] proto[3] bitmask[10082] t38_inhibit[0] global_fax[1] t38fax[1] Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_set_pref_codec_list: Using Voice Class Codec, tag = 1 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_set_pref_codec_list: First preferred codec(bytes)=6(160) Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_get_peer_info: Preferred codec set to G711_ALAW_64K with Bytes = 160 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_get_peer_info: Flow Mode set to FLOW_THROUGH Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_get_peer_info: peer: 45841E90, peer->voice_peer_tag: 3F9, ccb: 480CE850 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_set_h323_parms_from_dp: ccb h245addr bits = system[0x0007] Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_set_h323_parms_from_dp: ccb ccm bits = system[0x0028] Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_update_setup_callinfo: callingNumber = 04917662032618 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_update_setup_callinfo: called_oct3 = 0xA1, calling_oct3 = 0x11, calling_oct3a = 0x83 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_set_h323_control_options_outgoing: h245 sm mode = 271 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_set_h323_control_options_outgoing: h323_ctl=0x20 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_call_setup: No account/pin number available Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_call_setup_normal: Entry Mar 11 16:50:49.732: //33305/108304C480A7/H323/cch323_store_call_info: Call_setup Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:50:49.904: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:49.904: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xB internal event to H225 SM Mar 11 16:50:49.904: //33305/108304C480A7/H323/run_h225_sm: Received event H225_EV_SETUP while at state H225_IDLE Mar 11 16:50:49.904: //33305/108304C480A7/H323/check_qos_and_send_setup: Setup ccb 0x480CE850 Mar 11 16:50:49.904: //33305/108304C480A7/H323/cch323_rotary_validate: No peer_ccb available Mar 11 16:50:49.904: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0xE internal event to H225 SM Mar 11 16:50:49.904: //33305/108304C480A7/H323/run_h225_sm: Received event H225_EV_FS_SETUP while at state H225_IDLE Mar 11 16:50:49.904: //33305/108304C480A7/H323/idle_fsSetup_hdlr: Setup ccb 0x480CE850 Mar 11 16:50:49.904: //33305/108304C480A7/H323/idle_fsSetup_hdlr: send_fastStart_setup called Mar 11 16:50:49.904: //33305/108304C480A7/H323/send_fastStart_setup: Entry Mar 11 16:50:49.904: //33305/108304C480A7/H323/cch323_build_local_encoded_fastStartOLCs: state_mc_mode=0x10F on outbound leg Mar 11 16:50:49.904: //33305/108304C480A7/H323/cch323_build_local_encoded_fastStartOLCs: srcAddress = 0xA160302, h245_lport = 0, flow mode = 1, minimum_qos=0 Mar 11 16:50:49.904: //33305/108304C480A7/H323/h245_set_local_audio_mask: Near-end Pref Codecs = G711_ALAW_64K G711_ULAW_64K G729IETF Mar 11 16:50:49.904: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: current codec = 6:160:160 Mar 11 16:50:49.904: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: Codec is G711_ALAW_64K Mar 11 16:50:49.904: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: Filling in qosCapability field to 0 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: current codec = 5:160:160 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: Codec is G711_ULAW_64K Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: Filling in qosCapability field to 0 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: current codec = 16:20:20 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: Codec is G729IETF Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_generic_open_logical_channel: Filling in qosCapability field to 0 Mar 11 16:50:49.908: //33305/108304C480A7/H323/generic_send_setup: Entry Mar 11 16:50:49.908: //33305/108304C480A7/H323/generic_send_setup: generic_send_setup: is_overlap = 0, info_complete = 0 Mar 11 16:50:49.908: //33305/108304C480A7/H323/generic_send_setup: sending calling IE Mar 11 16:50:49.908: //33305/108304C480A7/H323/generic_send_setup: ====== PI = 0 Mar 11 16:50:49.908: //33305/108304C480A7/H323/generic_send_setup: Send infoXCap=144, infoXRate=16, rateMult=0, xMode=128, info_layer1_prot=163 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_h225_copy_send_rawMsg: Copy raw message data to nonStdInfo Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_h225_copy_send_rawMsg: Copy tunnelled GTD/ISUP content Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: (for cch323_h225_copy_send_rawMsg): raw message is 231 bytes: Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 04 03 80 90 A3 18 03 A1 83 81 6C 0F 11 83 34 39 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 31 37 36 36 32 30 33 32 36 31 38 70 0A A1 32 30 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 37 31 35 30 32 34 35 A1 1C BD 9E 81 00 03 67 74 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 64 00 00 00 B2 49 41 4D 2C 0D 0A 50 52 4E 2C 69 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 73 64 6E 2A 2C 2C 41 54 54 34 2A 2C 0D 0A 55 53 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 49 2C 72 61 74 65 2C 63 2C 73 2C 63 2C 31 0D 0A Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 55 53 49 2C 6C 61 79 31 2C 61 6C 61 77 0D 0A 54 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 4D 52 2C 30 30 0D 0A 43 50 4E 2C 30 34 2C 2C 31 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 2C 32 30 37 31 35 30 32 34 35 0D 0A 43 47 4E 2C Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 30 36 2C 2C 31 2C 79 2C 34 2C 34 39 31 37 36 36 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 32 30 33 32 36 31 38 0D 0A 43 50 43 2C 30 39 0D Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 0A 46 43 49 2C 2C 2C 2C 2C 2C 2C 79 2C 0D 0A 47 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 43 49 2C 31 30 38 33 30 34 63 34 65 65 63 32 31 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 31 64 63 38 30 61 37 30 30 31 62 30 63 36 33 65 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_prnt_rawmsg: 35 35 30 0D 0A 0D 0A Mar 11 16:50:49.908: //33305/108304C480A7/H323/generic_send_setup: src address = 10.22.3.2; dest address = 10.193.0.18 Mar 11 16:50:49.908: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:50:49.908: //33305/108304C480A7/H323/cch323_h225_set_new_state: Changing from H225_IDLE state to H225_REQ_FS_SETUP state Mar 11 16:50:49.908: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x0 internal event to H245 IWF SM Mar 11 16:50:49.908: //33305/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_FASTSTART while at state IWF_IDLE Mar 11 16:50:49.908: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:50.008: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:50:50.008: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:50:50.008: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:50:50.008: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: Retry, fd=2 Mar 11 16:50:50.108: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:50:50.108: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:50:50.108: //-1/xxxxxxxxxxxx/H323/h323_gw_start_sock_blocked_timer: fd 2 Mar 11 16:50:50.108: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: Retry, fd=2 Mar 11 16:50:50.208: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_SOCK_WRITE_BLOCKED_TIMER] expired Mar 11 16:50:50.208: //-1/xxxxxxxxxxxx/H323/h323_gw_sock_block_timer_expired: fd 2 Mar 11 16:50:50.208: //-1/xxxxxxxxxxxx/H323/h323_gw_stop_sock_blocked_timer: fd 2 Mar 11 16:50:50.336: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1 Mar 11 16:50:50.336: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x47FFB918, len=45, msgPtr=0x48675E38 Mar 11 16:50:50.336: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225 Mar 11 16:50:50.336: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type RELEASEIND_CHOSEN Mar 11 16:50:50.336: //33305/108304C480A7/H323/release_ind: Disconnect cause 1 location code 0 Mar 11 16:50:50.336: //-1/xxxxxxxxxxxx/H323/h323_set_release_source_for_peer: ownCallId[33305], src[4] Mar 11 16:50:50.336: //33305/108304C480A7/H323/cch323_h225_receiver: RELEASEIND_CHOSEN: src address = 10.22.3.2; dest address = 10.193.0.18 Mar 11 16:50:50.336: //33305/108304C480A7/H323/run_h225_sm: Received event H225_EV_RELEASE_IND while at state H225_REQ_FS_SETUP Mar 11 16:50:50.336: //33305/108304C480A7/H323/cch323_traverse_enum_contact_list: State = 2 Mar 11 16:50:50.336: //33305/108304C480A7/CCAPI/cc_api_call_disconnected: Cause Value=1, Interface=0x46C1EC74, Call Id=33305 Mar 11 16:50:50.336: //33305/108304C480A7/CCAPI/cc_api_call_disconnected: Call Entry(Responsed=TRUE, Cause Value=1, Retry Count=0) Mar 11 16:50:50.340: //33303/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources: release reserved xcoding resource. Mar 11 16:50:50.340: //33305/108304C480A7/CCAPI/ccCallSetAAA_Accounting: Accounting=0, Call Id=33305 Mar 11 16:50:50.340: //33305/108304C480A7/CCAPI/ccCallDisconnect: Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=1) Mar 11 16:50:50.340: //33305/108304C480A7/CCAPI/ccCallDisconnect: Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1) Mar 11 16:50:50.340: //33305/108304C480A7/CCAPI/cc_api_get_transfer_info: Transfer Number Is Null Mar 11 16:50:50.340: //33305/108304C480A7/H323/cch323_do_call_disconnect: gw_id=1, discCause=1 Mar 11 16:50:50.340: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x9 internal event to H225 SM Mar 11 16:50:50.340: //33305/108304C480A7/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_REQ_FS_SETUP Mar 11 16:50:50.340: //33305/108304C480A7/H323/cch323_h225_send_release: Cause = 1; Location = 0 Mar 11 16:50:50.340: //33305/108304C480A7/H323/cch323_h225_send_release: h225TerminateRequest: src address = 169214722; dest address = 10.193.0.18 Mar 11 16:50:50.340: //33305/108304C480A7/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_SETUP state to H225_IDLE state Mar 11 16:50:50.340: //33305/108304C480A7/H323/cch323_call_generic_cleanup: Disconnected flag 1 Mar 11 16:50:50.340: //33305/108304C480A7/H323/cch323_store_call_history_entry: Call Active Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:50:50.340: //33305/108304C480A7/H323/cch323_store_call_history_entry: Call History Playout Mode: 1,Init 60, Min 40, Max 250, Fax 300 Mar 11 16:50:50.340: //-1/xxxxxxxxxxxx/H323/h323_gw_clean_send_blocked_watch: fd 2 Mar 11 16:50:50.340: //33305/108304C480A7/H323/run_h245_iwf_sm: received IWF_EV_H245_DISCONN while at state IWF_IDLE Mar 11 16:50:50.340: //33305/108304C480A7/H323/defaultHdlr: DEFAULT: Received IWF_EV_H245_DISCONN in state IWF_IDLE Mar 11 16:50:50.340: //-1/xxxxxxxxxxxx/H323/cch323_cleanup_xport: hashDestroy for TcpFDTbl Mar 11 16:50:50.340: //33305/108304C480A7/CCAPI/cc_api_call_disconnect_done: Disposition=0, Interface=0x46C1EC74, Tag=0x0, Call Id=33305, Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0) Mar 11 16:50:50.340: //33305/108304C480A7/CCAPI/cc_api_call_disconnect_done: Call Disconnect Event Sent Mar 11 16:50:50.340: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:50:50.340: :cc_free_feature_vsa freeing 46FE0A20 Mar 11 16:50:50.340: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:50:50.340: vsacount in free is 1 Mar 11 16:50:50.340: //-1/xxxxxxxxxxxx/H323/cch323_call_generic_cleanup: Freeing ccb (0x480CE850) Mar 11 16:50:50.348: //33303/108304C480A7/CCAPI/ccCallDisconnect: Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0) Mar 11 16:50:50.348: //33303/108304C480A7/CCAPI/ccCallDisconnect: Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1) Mar 11 16:50:50.348: //33303/108304C480A7/CCAPI/cc_api_get_transfer_info: Transfer Number Is Null Mar 11 16:50:50.432: //33303/108304C480A7/CCAPI/cc_api_call_disconnect_done: Disposition=0, Interface=0x48675B98, Tag=0x0, Call Id=33303, Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0) Mar 11 16:50:50.432: //33303/108304C480A7/CCAPI/cc_api_call_disconnect_done: Call Disconnect Event Sent Mar 11 16:50:50.432: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:50:50.432: :cc_free_feature_vsa freeing 46FE0F30 Mar 11 16:50:50.432: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa: Mar 11 16:50:50.432: vsacount in free is 0 ASM-111-VR# ASM-111-VR# ASM-111-VR# ASM-111-VR#