Hi,
We have an issue with calls being dropped after a number of seconds, when they get picked up by our voice mail system.
See the figure below for a graph of our voice network. Calls are coming in via ISDN, they are transfered to a Gatekeeper with voice gateway functions, and when the phone number is registered at the gatekeeper, it will be transfered to the corresponing voice gateway. So far everything is working fine.
When the phone number is not registered with the gatekeeper, it will be hunted from the RAS dial-peer to a 'regular' H.323 dial-peer towards a gateway that will connect the call with a SIP server providing voice mail services. When the SIP server answers the call immediately, the call gets dropped after aproximately 8 seconds. When a softphone is connected to the SIP server, and we wait for 10 seconds before answering the call the call does not get dropped.
We have gathered information on the ISDN voice gateway and the gatekeeper with the following commands:
debug cch323 h225
debug cch323 h245
voice iec syslog
When the call gets dropped the following messages are logged on the ISDN voice gateway:
Apr 8 14:24:36.154 CEST: //4729696/113C166894B2/H323/cch323_run_h245_cap_out_sm: Received H245_EVENT_CAP_TIMER_EXPIRY while at state AWAITING_RESPONSE
Apr 8 14:24:36.154 CEST: %VOICE_IEC-3-GW: H323: Internal Error (TCS ack wait timeout): IEC=1.1.183.5.63.0 on callID 4729696 GUID=113C16689F7E11E294B2001C58A81420
Apr 8 14:24:36.154 CEST: //4729696/113C166894B2/H323/h245_cap_out_set_new_state: changing from AWAITING_RESPONSE state to IDLE state
Apr 8 14:24:36.154 CEST: //4729696/113C166894B2/H323/run_h225_sm: Received event H225_EV_TRANSMIT_TUNNELING while at state H225_FS_ACTIVE
Apr 8 14:24:36.154 CEST: //4729696/113C166894B2/H323/run_h245_iwf_sm: received IWF_EV_CAP_REJ while at state IWF_AWAIT_CAP_MSD_RESP
Apr 8 14:24:36.154 CEST: //4729696/113C166894B2/H323/h245_iwf_set_new_state: changing from IWF_AWAIT_CAP_MSD_RESP state to IWF_IDLE state
Apr 8 14:24:36.154 CEST: //4729696/113C166894B2/H323/run_h225_sm: Received event H225_EV_H245_FAILED while at state H225_FS_ACTIVE
Apr 8 14:24:36.154 CEST: //4729696/113C166894B2/H323/cch323_h225_send_release: Cause = 41; Location = 3
Apr 8 14:24:36.154 CEST: //4729696/113C166894B2/H323/cch323_h225_send_release: h225TerminateRequest: src address = -1052560798; dest address = x.y.z.254
Apr 8 14:24:36.158 CEST: //4729696/113C166894B2/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_FS_ACTIVE
Apr 8 14:24:36.158 CEST: //4729696/113C166894B2/H323/cch323_h225_set_new_state: Changing from H225_FS_ACTIVE state to H225_IDLE state
Apr 8 14:24:36.158 CEST: //4729696/113C166894B2/H323/run_h245_iwf_sm: received IWF_EV_H245_DISCONN while at state IWF_IDLE
Apr 8 14:24:36.158 CEST: //4729696/113C166894B2/H323/defaultHdlr: DEFAULT: Received IWF_EV_H245_DISCONN in state IWF_IDLE
And on the Gatekeeper + Gateway:
Apr 8 14:27:18.430 CEST: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type FACILIND_CHOSEN
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/cch323_h225_receiver: FACILIND_CHOSEN: src address = x.y.z.252; dest address = a.b.c.98
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/run_h225_sm: Received event H225_EV_FACILITY_IND while at state H225_FS_ACTIVE
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/run_h245_iwf_sm: received IWF_EV_PROC_TUNNEL while at state IWF_AWAIT_MSD_RESP
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/cch323_run_h245_cap_in_sm: Received H245_EVENT_CAP_REL while at state AWAITING_RESPONSE
Apr 8 14:27:18.434 CEST: %VOICE_IEC-3-GW: H323: Internal Error (TCS rel received): IEC=1.1.180.5.44.0 on callID 7102233 GUID=72C3A0579F7E11E294B9001C58A81420
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/h245_cap_in_set_new_state: changing from AWAITING_RESPONSE state to IDLE state
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/run_h245_iwf_sm: received IWF_EV_CAP_REJ while at state IWF_AWAIT_MSD_RESP
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/errHdlr: ERROR: Received Unexpected IWF_EV_CAP_REJ in state IWF_AWAIT_MSD_RESP
Apr 8 14:27:18.434 CEST: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type RELEASEIND_CHOSEN
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/release_ind: Disconnect cause 41 location code 4
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/cch323_h225_receiver: RELEASEIND_CHOSEN: src address = x.y.z.252; dest address = a.b.c.98
Apr 8 14:27:18.434 CEST: //7102233/72C3A05794B9/H323/run_h225_sm: Received event H225_EV_RELEASE_IND while at state H225_FS_ACTIVE
Apr 8 14:27:18.438 CEST: //7102233/72C3A05794B9/H323/run_h225_sm: Received event H225_EV_RELEASE while at state H225_FS_ACTIVE
Apr 8 14:27:18.438 CEST: //7102233/72C3A05794B9/H323/cch323_h225_set_new_state: Changing from H225_FS_ACTIVE state to H225_WAIT_FOR_DRQ state
Apr 8 14:27:18.438 CEST: //7102233/72C3A05794B9/H323/cch323_h225_send_release: Cause = 41; Location = 4
Apr 8 14:27:18.438 CEST: //7102233/72C3A05794B9/H323/cch323_h225_send_release: h225TerminateRequest: src address = 1572780284; dest address = a.b.c.98
Another call with
debug cch323 session
on the ISDN gateway:
Apr 8 15:09:37.739 CEST: //-1/xxxxxxxxxxxx/H323/cch323_timer_dispatch: Timer[CCH323_H245_CAP_TIMER] expired
Apr 8 15:09:37.739 CEST: //-1/xxxxxxxxxxxx/H323/cch323_iev_queue_service: Dispatch 0x4 internal event to H245 CAP OUT SM
Apr 8 15:09:37.739 CEST: //-1/xxxxxxxxxxxx/H323/h323_set_cc_cause_for_spi_err:
Categorized cause:41, category:183
Apr 8 15:09:37.739 CEST: %VOICE_IEC-3-GW: H323: Internal Error (TCS ack wait timeout): IEC=1.1.183.5.63.0 on callID 4730099 GUID=5C6AF76D9F8411E29505001C58A81420
The questions is whether it is possible to do dial-peer hunting from a RAS dial-peer to a regular H.323 dial-peer. Are there any timers we need to consider? It seems as if the secondary H.323 dial-peer gets activated, while the primary RAS dial-peer has not timed out properly... When the RAS dial-peer times out, it disconnects the call that was initated via the secondary dial-peer.
