Early media call fails if remote party answers during media streaming

Jonathan Els · ‎09-13-2017

Hi,

I have written an IVR script to handle a requirement to support playing prompts to either play prompt then handoff call, drop a call after playing, or stream a prompt as early media.

Platform: ISR4331/K9
Firmware: 15.5(1)S
Call scenario: CUBE call

I have hit one issue with the early media scenario. I am using the following approach to initiate the playback:

proc playEarlyMedia { prompt dnis } {

leg progress leg_incoming -p 8

media play leg_incoming $prompt

leg setup $dnis callInfo leg_incoming

# proceed directly to outbound calling

fsm setstate PLACECALL

}

The full script is attached.

With this, the media file is streamed successfully. However, what I find is that, if the remote user answers the call while the prompt is still playing, the call fails. However, if the prompt finishes played, the call is set up successfully.

I have attached comparative traces for successful and fails scenarios. Can anyone suggest what I need to modify to prevent the call drop? I'm quite sure that my requirement is contained in the CVP ringback.tcl script, but sadly I don't have access to this for reference.

Any assistance is greatly appreciated.

Raghavendra G V · ‎09-13-2017

Hi Jonathan,

Please issue media stop command before handoff command.

media stop leg_incoming
handoff appl leg_all default

Thanks,
Raghavendra

Jonathan Els · ‎09-13-2017

Hi,

Thanks for the reply.

This is not a handoff scenario. That code (handoff appl leg_all default) never gets executed in the call flow scenario for early media.

Why are you suggesting a media stop though?

Raghavendra G V · ‎09-13-2017

From the failed_early_media_call logs you shared, handoff command is executed after call setup done.You need to stop any media file if it is still playing before handoff command otherwise handoff will be failed.

Sep 12 15:30:14.637: //37922//AFW_:/AFW_FSM_Drive: ACTION BEGIN: ------(PLACECALL[4],ev_setup_done[250])---[act_CallSetupDone]------
Sep 12 15:30:14.637: //37922//TCL :/tcl_PutsObjCmd: Entering act_CallSetupDone
Sep 12 15:30:14.637:
Sep 12 15:30:14.637: //37922//TCL :/tcl_InfotagObjCmd: infotag get evt_status
Sep 12 15:30:14.637: //37922//TCL :/tcl_InfotagGetObjCmd: infotag get evt_status
Sep 12 15:30:14.637: //37922//AFW_:/vtr_ev_status: argc 2 argindex 2
Sep 12 15:30:14.637: //37922//TCL :/tcl_PutsObjCmd: Call Setup Successful
Sep 12 15:30:14.637:
Sep 12 15:30:14.637: //37922//TCL :/tcl_HandoffObjCmd: handoff appl leg_all default
Sep 12 15:30:14.637: //37922//TCL :/tcl_handoff_common: appl leg_all default
Sep 12 15:30:14.637: //37922//AFW_:/vtd_lg_all: argc 3
Sep 12 15:30:14.637: //37922//AFW_:/vtd_lg_all: Legs [37925 37922 ]

Thanks,
Raghavendra

Jonathan Els · ‎09-13-2017

Ah, ok I see.

As I'm trying to handle multiple scenarios in one script, at that point, media may, or may not be playing. If it isn't still playing, and I use media stop leg_incoming, will this create any failure? If so, is there an API call I can use to check if media is still playing on a particular call leg?

Raghavendra G V · ‎09-13-2017

No need to check, there is no such command. You can just use media stop command before handoff command it stops the prompt that is currently playing on the specified call leg.

You can remove handoff command if you don't want to handoff to default app after call setup done.

proc act_CallSetupDone { } {

puts "Entering act_CallSetupDone"
set status [infotag get evt_status]

    if { $status == "ls_000"} {
        puts "Call Setup Successful"
        #handoff appl leg_all default
        # test with removing this direct proc call. it should not be required...
        #act_Cleanup
    } else {
        act_Abort
    }
}

Thanks,
Raghavendra

Jonathan Els · ‎09-13-2017

Excellent, I think you've given me a lot to work with here. Let me review my call flows which lead into the act_CallSetupDone proc and see if and where I can amend this.

Will report back asap. Thank you for your prompt responses!

Jonathan Els · ‎09-15-2017

Neither of these approaches is working. If I remove the handoff, the call fails. Even if I use a media stop, the sam error occurs.

Raghavendra G V · ‎09-15-2017

could you please share the logs.

Thanks,

Raghavendra

Jonathan Els · ‎09-15-2017

Sorry, I was missing the obvious when trying to upload a new attachment.

Please see the below error in the new logs I sent. These are being logged by CCAPI inout. This doesn't happen if I let the call complete:

This is the original failed call with more debugs. If you look, you'll see the following shown the CCAPI logging:

74723: Sep 15 14:21:11.226: //-1//AFW_:/AFW_Process_GetAppQEvent: Event[APP_EV_MEDIAFORK_CONF_CREATE_DONE(309)] {

074724: Sep 15 14:21:11.226: //-1//AFW_:/AFW_Process_GetAppQEvent: EXECENV[0x7FE68C883E18][Default]

074725: Sep 15 14:21:11.226: //-1//AFW_:/AFW_Process_GetAppQEvent: LEG[46149][LEG_OUTCONNECTED(10)][Cause(0)]

074726: Sep 15 14:21:11.226: //-1//AFW_:/AFW_Process_GetAppQEvent: }

074727: Sep 15 14:21:11.226: //-1//SSIN:/AFW_SS_MapEvent: No mapping required

074728: Sep 15 14:21:11.226: //46149/597C2E000000/AFW_:/AFW_M_Leg_EventPreProcess: LEG[46149 ][LEG_OUTCONNECTED(10)][Cause(0)]

074729: Sep 15 14:21:11.226: //46149/597C2E000000/AFW_:/AFW_Object_WalkListeners:

074730: Sep 15 14:21:11.226: //46149/597C2E000000/AFW_:/AFW_M_Object_ShowListeners: START

074731: Sep 15 14:21:11.226: //-1//AFW_:/AFW_M_Object_ShowListeners: MOD[TclModule_0x7FE68C8870D8_0_1460009122] (

074732: Sep 15 14:21:11.226: //-1//AFW_:/AFW_M_Object_ShowListeners: LEG[46146][LEG_INCCONNECTED(5)][Cause(0)]

074733: Sep 15 14:21:11.226: //-1//AFW_:/AFW_M_Object_ShowListeners: CON[281][CONNECTION_CONFED(2)] {

074734: Sep 15 14:21:11.226: //-1//AFW_:/AFW_M_Object_ShowListeners: LEG[46146][LEG_INCCONNECTED(5)][Cause(0)],

074735: Sep 15 14:21:11.226: //-1//AFW_:/AFW_M_Object_ShowListeners: LEG[46149][LEG_OUTCONNECTED(10)][Cause(0)]

074736: Sep 15 14:21:11.226: //-1//AFW_:/AFW_M_Object_ShowListeners: }

074737: Sep 15 14:21:11.226: //-1//AFW_:/AFW_M_Object_ShowListeners: LEG[46149][LEG_OUTCONNECTED(10)][Cause(0)]

074738: Sep 15 14:21:11.226: //-1//AFW_:/AFW_M_Object_ShowListeners: )

074739: Sep 15 14:21:11.227: //46149/597C2E000000/AFW_:/AFW_M_Object_ShowListeners: END

074740: Sep 15 14:21:11.227: //46149/597C2E000000/AFW_:/AFW_Object_WalkListeners: Entering Module : TclModule

074741: Sep 15 14:21:11.227: //-1//AFW_:EE7FE68C883E18000:/AFW_ExecEnv_SetModuleScope: NULL ---> TclModule_0x7FE68C8870D8_0_1460009122

074742: Sep 15 14:21:11.227: //-1//AFW_:EE7FE68C883E18000:/AFW_M_TclModule_Action:

074743: Sep 15 14:21:11.227: //-1//AFW_:EE7FE68C883E18000:/AFW_TclModule_DefaultEvHandling:

074744: Sep 15 14:21:11.227: //-1//AFW_:/C_ServiceSession_Event_Handler:

074745: Sep 15 14:21:11.227: //46149/597C2E000000/AFW_:/C_ServiceSession_Event_Handler: Received event APP_EV_MEDIAFORK_CONF_CREATE_DONE[309] in Main Loop

074746: Sep 15 14:21:11.227: //-1//AFW_:EE7FE68C883E18000:/AFW_ExecEnv_SetModuleScope: TclModule_0x7FE68C8870D8_0_1460009122 ---> NULL

074747: Sep 15 14:21:11.227: //46149/597C2E000000/AFW_:/AFW_M_Event_Free:

074748: Sep 15 14:21:11.227: //-1//AFW_:EE7FE68C883E18000:/AFW_ExecEnv_CloseIfDone: Cmd Count: 3

074749: Sep 15 14:21:11.227: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event(0)

074750: Sep 15 14:21:11.227: //-1//AFW_:/AFW_M_Event_Free:

074751: Sep 15 14:21:11.227: //-1//AFW_:/AFW_M_Event_Free: Null or invalid event context: for event APP_EV_NULL

074752: Sep 15 12:21:11.227: %VOICE_IEC-3-GW: SIP: Internal Error (Software Error): IEC=1.1.180.7.13.0 on callID 46146 GUID=597C2E0000010000000001D50E71900A

074753: Sep 15 14:21:11.227: //46146/597C2E000000/CCAPI/cc_api_call_disconnected:

Cause Value=47, Interface=0x7FE68C51AE10, Call Id=46146

074754: Sep 15 14:21:11.227: //46146/597C2E000000/CCAPI/cc_api_call_disconnected:

Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)

074755: Sep 15 12:21:11.227: %VOICE_IEC-3-GW: SIP: Internal Error (Software Error): IEC=1.1.180.7.13.0 on callID 46149 GUID=597C2E0000010000000001D50E71900A

074756: Sep 15 14:21:11.228: //46149/597C2E000000/CCAPI/cc_api_call_disconnected:

Cause Value=47, Interface=0x7FE68C51AE10, Call Id=46149

074757: Sep 15 14:21:11.228: //46149/597C2E000000/CCAPI/cc_api_call_disconnected:

Call Entry(Responsed=TRUE, Cause Value=47, Retry Count=0)

074758: Sep 15 14:21:11.229: //46146/597C2E000000/CCAPI/cc_process_notify_bridge_done:

Conference Id=0x119, Call Id1=46146, Call Id2=46149

074759: Sep 15 14:21:11.229: //-1//SERV:/AFW_Service_Process_Space:

074760: Sep 15 14:21:11.229: Process Started

074761: Sep 15 14:21:11.229: //-1//AFW_:/AFW_Process_Register: ccAppInitialize(name: _ManagedAppProcess_Default)

Raghavendra G V · ‎09-15-2017

Please share complete logs as attchement. I checked your tcl script leg connect is not issued, instead leg progress used any specific reason.

please issue leg connect before media play and try.

proc playEarlyMedia { prompt dnis } {

    leg progress leg_incoming -p 8
   leg connect leg_incoming
    media play leg_incoming $prompt

leg setup $dnis callInfo leg_incoming

# proceed directly to outbound calling

fsm setstate PLACECALL

}

Thanks,
Raghavendra

Jonathan Els · ‎09-16-2017

Hi,

The full logs are attached. Please see errorstate.txt.zip. That is a full debug.

I don't want to connect the call before playing the prompt. I want to stream early media, so this must happen instead of ringback. At the moment, when I initiate the call, I see a 183 Session in Progress sent to calling party because of the progress_indicator and the media play. This is exactly the behaviour that I want. Is there a way to do this without connecting the call initially? As long as the prompt finishes, the call does set up without any issues.

If you look in the script, you'll see I have an alternate "handoff" scenario where I do what you're suggesting - connect, play prompt, then dial remote party.

If I must connect the call first, can you advise on an approach to connect, play media, simultaneously dial out to the remote party, then do a media stop and join the two legs as soon as the remote side answers?

I'd greatly prefer the first option, as that is really my exact requirement. But if this is a software limitation, that's OK, but would just like to understand why.

Raghavendra G V · ‎09-17-2017

I am not sure why below SIP error is occurred.
074752: Sep 15 12:21:11.227: %VOICE_IEC-3-GW: SIP: Internal Error (Software Error): IEC=1.1.180.7.13.0 on callID 46146 GUID=597C2E0000010000000001D50E71900A
074753: Sep 15 14:21:11.227: //46146/597C2E000000/CCAPI/cc_api_call_disconnected:
Cause Value=47, Interface=0x7FE68C51AE10, Call Id=46146

Please share full logs with below debugs
debug ccsip all
debug voip app
debug voip ccapi inout

You can play prompt and simultaneously place call as below without incoming leg, so ring back tone will not be played to incoming leg, only media file will be played. Media need to played till call is answered
    leg connect leg_incoming
    media play leg_incoming $prompt
    leg setup $dnis callInfo

Once call is answered (ls_000) you can issue media stop and create connection.
media stop leg_incoming
connection create leg_incoming leg_outgoing

Once script receive ev_create_done event, you can handoff call to default.
handoff appl leg_all default

Thanks,
Raghavendra

Jonathan Els · ‎09-21-2017

Thanks for the suggestion.

I edited the following procedures in my script to match your requested config change:

proc playEarlyMedia { prompt dnis } {

leg progress leg_incoming -p 8

leg connect leg_incoming

media play leg_incoming $prompt

leg setup $dnis callInfo leg_incoming

# proceed directly to outbound calling

fsm setstate PLACECALL

}

I then added the following to act_CallSetupDone :

proc act_CallSetupDone { } {

puts "Entering act_CallSetupDone"

set status [infotag get evt_status]

if { $status == "ls_000"} {

puts "Call Setup Successful"

media stop leg_incoming

connection create leg_incoming leg_outgoing

handoff appl leg_all default

act_Cleanup

} else {

act_Abort

}

After doing this, the call fails with an internal script error:

107097: Sep 21 12:03:31.568: //62988//TCL :/tcl_PutsObjCmd: Call Setup Successful

107098: Sep 21 12:03:31.568:

107099: Sep 21 10:03:31.568: %VOICE_IEC-3-GW: TCL_IVR: Internal Error (Invalid action in script): IEC=1.1.180.2.25.1 on callID 62988 GUID=1C9EB40000010000000001F50E71900A

107100: Sep 21 12:03:31.568: //62988//AFW_:/AFW_FSM_Drive: Tcl_Eval to drive FSM inside Tcl modulespace. code=1 code=ERROR

107101: Sep 21 12:03:31.568: TCL script failure

Result:

Illegal Parameters. Leg1 is already conferencedleg_incoming

107102: Sep 21 12:03:31.568: TCL script failure errorInfo:

Illegal Parameters. Leg1 is already conferencedleg_incoming

while executing

"connection create leg_incoming leg_outgoing

(procedure "act_CallSetupDone" line 10)

invoked from within

"act_CallSetupDone"

So it doesn't look like your suggestion is working.

I will update a full debug for the original call with is causing the error with the debugs that you've requested, not for the above.

Raghavendra G V · ‎09-21-2017

Please remove leg_incoming to leg setup command and try. you can handoff to default after you got ev_create_done event.

proc playEarlyMedia { prompt dnis } {

# leg progress leg_incoming -p 8

leg connect leg_incoming

media play leg_incoming $prompt

leg setup $dnis callInfo

# proceed directly to outbound calling

fsm setstate PLACECALL

}

proc act_CallSetupDone { } {

puts "Entering act_CallSetupDone"

set status [infotag get evt_status]

if { $status == "ls_000"} {

puts "Call Setup Successful"

media stop leg_incoming

connection create leg_incoming leg_outgoing

# handoff appl leg_all default

# act_Cleanup

} else {

act_Abort

}

Thanks,

Raghavendra