Hello,
Some background:
Using HMP 3.0 310
Using Visual Studio with GC wrapper.
The issue:
So, I have my application running. Everything is fine, I can make calls, receive calls, play audio, retrieve DTMF from user.
The issue arises when I have my application running in the Visual Studio debugger, I have a call on a line, and I press the "Stop Debugging (Shift + F5)" button. This instantly closes my app with the call on the line.
Now, when I restart my application, the first call on the line has a issue. Audio can still be played on the line for the first call. But Dialogic doesn't signal at all for DTMF digits entered by the user. This goes for dx_playiottdata and dx_getdig.
Now after the first call is hung up I get this in the rtf log:
07/26/2012 07:38:46.989 8252 8468 gc ERR1 gcrtcm_mgr iptB1T1 ----- ChangeGCCallState() - Invalid transition (State: 32, Event: GCEV_DROPCALL)
07/26/2012 07:38:46.989 8252 8468 gc ERR1 gccme iptB1T1 ----- gc_cme_ChangeGCCallState(cclibcrn:0x1h, cclibid:8, event:GCEV_DROPCALL(0x805h)) returns:65.
07/26/2012 07:38:46.989 8252 8468 gc ERR1 gcep iptB1T1 ----- gc_ep_ProcessGCEvent() - gc_cme_ChangeGCCallState() failed with event GCEV_DROPCALL(0x805h) on linedev:1, crn:0x1h
07/26/2012 07:38:46.989 8252 8468 gc_h3r ERR1 packer_main.cpp:464 ! 1 ! << putEvent :(*pglbGcFunc->gc_ep_ProcessGCEvent) failed with error 65 :(0x805) GCEV_DROPCALL :
07/26/2012 07:38:46.990 8252 8468 gc_h3r ERR1 ld_state.cpp:186 ! 1 ! << LD::sendDisconnectOrDrop:putEvent failed:
07/26/2012 07:38:46.990 8252 8468 gc_h3r ERR1 ld_state.cpp:1650 ! 1 ! << LD_Media::onStateDrop : sendDisconnectOrDrop() failed :
07/26/2012 07:38:46.990 8252 8468 gc_h3r ERR1 ld_state.cpp:666 ! 1 ! << LD_Media::ldStateMachine: st ST_DROP ev EV_DROP_SIGNALING :
07/26/2012 07:38:46.990 8252 8468 gc_h3r ERR1 ld_state.cpp:1964 ! 1 ! << LD_Media::signalingDrop ev EVENT_DROP_SIGNALING failed 10
07/26/2012 07:38:46.990 8252 8468 gc_h3r ERR1 crn_states.cpp:2849 ! 1 ! << ShCRN::onStateDisconnected : ev EventCallDrop :
07/26/2012 07:38:46.990 8252 8468 gc_h3r ERR1 sm_callcontrol.:966 ! 1 ! << DropCall: pCrn->dropCall failed
07/26/2012 07:38:46.990 8252 8468 gc ERR1 gclib iptB1T1 ::::> gc_DropCall(crn:0x8000001h, cause:16, mode:async) - returns:-1
07/26/2012 07:38:46.996 8252 8468 gc_h3r ERR1 crn_states.cpp:2891 ! 1 ! << ShCRN::onStateRelease : ev EventCallDrop :[9]
07/26/2012 07:38:46.996 8252 8468 gc_h3r ERR1 sm_callcontrol.:966 ! 1 ! << DropCall: [9] pCrn->dropCall failed
07/26/2012 07:38:46.996 8252 8468 gc ERR1 gclib iptB1T1 ::::> gc_DropCall(crn:0x8000001h, cause:16, mode:async) - returns:-1
Still with me?
Ok, so first call is done. Second call happens and everything is back to being good. DTMF digits are received fine.
To me it seems like since the first instance of my application was abruptly shutdown without any call cleanup, the first call in the second instance of my app has the voice device in a invalid state.
If I shutdown my application cleanly this problem doesn't exist.
Solutions I have tried:
1. Opening, then closing, then opening the voice device when initially opening the channel device and voice device. Eg:
voiceDevice = dx_open(voiceString, 0);
if (dx_close(voiceDevice) == -1)
{
getErrorInfo("OpenHMPDevice::dx_close");
}
if (voiceDevice == -1)
getErrorInfo("OpenHMPDevice::dx_open");
return (-1);
2. Using gc_ResetLineDev once the voice and channel devices have been opened.
Neither one of these fixes my issue.
I have checked the voice device state using ATDX_STATE(voiceDevice); This always returns 1 meaning "CS_IDLE".
Any help to how I can clean up calls from a prior instance of my application running would be great!
Hi,
In the log snippet you sent I see no voice-related errors; there is an obvious internal state machine error saying that the gc_DropCall operation is invalid in the current state.
Do you do RFC2833 digits? If so, it may be related to the IPM device (the one responsible for RFC2833 processing) going out of state. Could you please add voice, DM3, IPM and IPVSC levels to the RtfConfigWin.xml and provide a log with the entire call, from gc_Open to gc_Drop?
Attached is my detailed RTF log.
And yes I am using RFC2833 for DTMF digits.
What I see here is that the app, for some reason, calls gc_DropCall twece, and the second dropCall fails, naturally:
// The first DropCall called upon GCEV_DISCONNECT:
07/26/2012 11:12:17.394 9832 6884 gc APPL gclib <:::: gc_DropCall(crn:0x8000001h, cause:16, mode:async) - entry
07/26/2012 11:12:17.394 9832 6884 gc APPL gcep iptB1T1 ----- GC event:0x805h(GCEV_DROPCALL) posted on linedev:1, crn:0x1h
// Success.
07/26/2012 11:12:17.394 9832 6884 gc APPL gclib iptB1T1 ::::> gc_DropCall(crn:0x8000001h, cause:16, mode:async) - returns:0
07/26/2012 11:12:17.395 9832 9348 gc INFO gclib ----- gc_GetMetaEvent() returns:0 on ldev:1, crn:0x8000001h with event:0x805h(GCEV_DROPCALL)
Now, instaed of rreleaseCall, the app call gc_DropCall again on same CRN. This call is out of call state and fails:
07/26/2012 11:12:17.399 9832 6884 gc APPL gclib <:::: gc_DropCall(crn:0x8000001h, cause:16, mode:async) - entry07/26/2012 11:12:17.400 9832 6884 gc DEBG gccme ----- gc_cme_GCCallStateTransitionEvt() - event:GCEV_TASKFAIL(0x801h) is NOT a transition event.
As far as digits a re concerned, I see at least 1 digit in the buffer when TDX_GETDIG returns. I do not see other issues besides the one above.
Hope this helps.
Well I don't see how the gc_DropCall being called twice would have anything to do with Dialogic not signaling that the user has pressed a DTMF digit while a voice file is being played.
Also, the reason for the double gc_DropCall (actually triple) being called is because TDX_GETDIG was fired from Dialogic AFTER the call was disconnected (Bye message).
I had
case (int)CommonDefs.VoxEvents.TDX_GETDIG:
if (this.LineState == States.LineState.Disconnected)
this.dialogicDevice.DropCall();
else
this.Call.SetDTMFDigits(this.dialogicDevice.Digits());
this.Call.DtmfDigitsEntered();
break;
I have since commented the drop call out.
As for when TDX_GETDIG fires:
Did you see that TDX_GETDIG is being fired AFTER
<-- BYE sip:111@192.168.1.197 SIP/2.0
was received? How does that make any sense?
Granted this is probably because I had called dx_getdig earlier.
Would a Wireshark trace along with RTF logs be better help to diagnose this problem?
That way you can see when the digits are coming across the wire.
Again, this only happens on the first call after the application has been forced closed while a call was on the line.
After the first call is cleaned up, everything goes correctly for the second call.
Thanks.
In this post I attached new RTF logs and a Wireshark capture.
No arguments the problem exists, nut because such scenario is not "valid" per se (we do not test such scenarios), I'm trying to find some workaround, so your debugging goes more smooth.
The TDX_GETDIG is reported when one of the termination conditions met. It has nothing to do with DISCONNECT. Normally, when the app gets DISCONNECT, it stops all voice activity with dx_stopch and calls gc_Drop/gc_Release immediately. TDX_GETDIG is not a call-related event, and the app should not rely on it to teardown the call.
Please enable all DM3 Voice and DM3 Low lables in the RtfConfig and send me more detailed log; I'd like to see what happens to the voice resource. To me, so far, it seems that the voice is OK, but the IPM device is not initialized properly, because the previous instance was not stopped closed, and some components may be still busy.
Could you please enable the lables above, clean the logs snd capture the whole log from the first run thru the end. It's important to see how device intialization goes.
Leonid,
Thanks for your help and time on this issue.
The requested information should be attached in this post.
I included my RtfConfigWin.xml also.
Thanks again,
Jesse
Jesse,
I adjusted the RtfConfiga bit.
Please copy over and restart HMP. Then make 1 call, collect digits, and kill the app while in the call with Shift-F5. Then start the app and make one more call. Then collect the logs and post here. I don't need wireshark at the moment.
Hello Leonid,
Attached is new RtfLogs.
Actions preformed:
So 3 calls, middle call being the problem call. Then after hangup of problem call, next call works correctly.
Yes, it looks like the IPM resources hang in a bad state when the application has gone, and no exit notification was sent down to the driver. When you release the first call, the involved IPM device restores it's state. Unfortunately, HMP does not provide an API to reset the IPM device upfront, so, I'm afraid, we'll need to live with it, provided you have a workaround (by losing the very first call). You may also try to put together some small helper app, which would open channels, make loopback calls (or calls to anywhere, even to a fake IP address) on all channels, drop/relesase the calls and close this app properly, then you can continue with yours. I'm not 100% sure it will helps (again, we don't test such scenarios), but chances are good it will.
