state Hanging up... [CommandLink]

[Lukas]

Hi,

which could be the reason VG is disconnecting the call Hanging up... [CommandLink]

Line 227029: 121015.106  11 160  52 5046 state [Transfer Call fa with CALLER ID] out_leg 14 <=> 52 xxxxxxxxxxx |
    Line 230631: 121016.678  11 160  52 5046       CallExistsOnLine true (connected) crn=60600a0
    Line 234545: 121025.749  11 160  52 5046       CallExistsOnLine true (connected) crn=60600a0
    Line 242638: 121033.752  11 160  52 5046       CallExistsOnLine true (connected) crn=60600a0
    Line 243444: 121035.142  11 160  52 5046       CallExistsOnLine true (connected) crn=60600a0
    Line 244594: 121036.020  11 160  52 5046       CallExistsOnLine true (connected) crn=60600a0
    Line 249796: 121042.768  11 160  52 5046       q_scr run   cmdHangupCall 0  action_id=0, crn=0 [0|0|0|0|0][CommandLink|||||] 00:00:00 max:5|22,0013
    Line 249797: 121042.768  11 160  52 5046       HangupCall qScr exec src=CommandLink, opt=, crn_in=0, L1=Connected, L2=Running_Normal, lPlayId=0, lRecId=0
    Line 249798: 121042.768  11 160  52 5046       HangupCall crn_connected=60600a0, crn_NewCallArriving=0, crn_CurrentMakeCall=0, crn_InProcessOfReleasing=0
    Line 249799: 121042.768  11 160  52 5046       hangup the 2nd leg of call - LineId=44, port=52
    Line 249800: 121042.768  11 160  52 5046       TsReset [HangupCall], OtherLegLid=44
    Line 249801: 121042.768  11 160  52 5046       q_scr +     evScriptEvent 0 CONFERENCE_END
    Line 249803: 121042.768  11 160  52 5046       q_tel +     cmd_TsReset 0 [MATCH_] [0,0,0,0,0,0,0,0][dtiB3T22||dtiB1T14|||||]
    Line 249804: 121042.768  11 160  52 5046       OtherLegLid_ClearBoth 160 44 as iLineIdOther_iConferenceOtherLegLid=160 caller:HangupCall
    Line 249809: 121042.769  11 160  52 5046       rv    add   Hangup_Source|CommandLink
    Line 249810: 121042.769  11 160  52 5046       HangupCall sScriptToRunOnHangup=[]
    Line 249818: 121042.769  11 160  52 5046       no script running on this line. AfterHangup script will not be ran.
    Line 249820: 121042.769  11 160  52 5046       rv    add   DropCall_Source|Hangup the Call 1
    Line 249822: 121042.769  11 160  52 5046       crn 0 set to crn_connected 60600a0
    Line 249823: 121042.769  11 160  52 5046       L1_set Disconnect_Pending (iScriptState=LS_XFER_9_WaitEndCall_OutLeg)
    Line 249824: 121042.769  11 160  52 5046       modCurrentModuleWs=51984196
    Line 249826: 121042.769  11 160  52 5046       ws    ScriptEvent CMD_HANGUPCALL,HangupCall 0,0,0 CommandLink||
    Line 249828: 121042.769  11 160  52 5046       ws    ScriptEvent taskParams.hash=-84638466
    Line 249829: 121042.769  11 160  52 5046       ws    CMD_HANGUPCALL
    Line 249830: 121042.769  11 160  52 5046       ws    taskParams.dtWsUserWorkItemCreated=2020-10-23 12:02:02
    Line 249831: 121042.769  11 160  52 5046       ws    CMD_HANGUPCALL ignore as WebRequestCompleted.
    Line 249832: 121042.770  11 160  52 5046 state Hanging up... [CommandLink] |
    Line 249833: 121042.770  11 160  52 5046       logs not written as LogEntryWritten=1
    Line 249834: 121042.770  11 160  52 5046       L2_set Idle_WaitingForNextCall  (HangupCall)
    Line 249835: 121042.770  11 160  52 5046       GoOnHoook_IssueDropCall start (crn_in=60600a0, crn_connected=60600a0, crn_makecall=0, crn_NewCallArriving=0, crn_InProcessOfReleasing=0, L1=Disconnect_Pending)
    Line 249837: 121042.770  11 160  52 5046 t     timer set   20 sec : EV_TIMEOUT_WAITFORIDLEAFTERDropCall
    Line 249839: 121042.770  11 160  52 5046       GoOnHoook_IssueDropCall: set crn_InProcessOfReleasing=60600a0
    Line 249840: 121042.770  11 160  52 5046       clear crn_connected
    Line 249841: 121042.770  11 160  52 5046       set crn_connected=0 visual_ivr_session_id=0 (called from GoOnHoook_IssueDropCall)
    Line 249859: 121042.770  11 160  52 5046       q_tel +     cmd_DropCall 60600a0 [] [0,0,0,0,0,0,0,0][|||||||]
    Line 249860: 121042.770  11 160  52 5046       GoOnHoook_IssueDropCall end
    Line 249879: 121042.770  11 160  52 5046       q_scr run   evScriptEvent 0 CONFERENCE_END action_id=0, crn=0 [0|0|0|0|0][|||||] 00:00:00.0020001 max:5|22,0013
    Line 249881: 121042.770  11 160  52 5046       evscr CONFERENCE_END 0  0|0|0  || LineState=LS_ENDINGCALL
    Line 249885: 121042.770  11 160  52 5046       LsEndingCall CONFERENCE_END 0
    Line 249955: 121042.819  11 160  52 5046       q_scr run   evCallState 0 GCEV_DROPCALL action_id=0, crn=60600a0 [1|0|32|0|0][|||||] 00:00:00 max:5|22,0013
    Line 249956: 121042.819  11 160  52 5046       callstate crn_event=60600a0 0|GCEV_DROPCALL state=1|Idle_NotYetReleased calldirection=0 gcCallState=32 [||], ScriptState=LS_ENDINGCALL
    Line 249957: 121042.819  11 160  52 5046       GCEV_DROPCALL handler: clear .iDialoutID and .guidDialoutGuid
    Line 249958: 121042.819  11 160  52 5046       LineEvCallState L1_current=Disconnect_Pending crn_event=60600a0,ev=0,GCEV_DROPCALL,0, sParam1=
    Line 249959: 121042.819  11 160  52 5046       LineEvCallState IDLE begin crn=60600a0
    Line 249960: 121042.819  11 160  52 5046       clear timer as timer event is WAITFORIDLEAFTERDropCall, and IDLE was received
    Line 249961: 121042.819  11 160  52 5046 t     timer clear (force=True)
    Line 249962: 121042.819  11 160  52 5046       setting L1=Idle_NotYetReleased as: crn_CurrentConnected crn_CurrentMakeCallAttempt crn_NewCallArriving all 0
    Line 249963: 121042.819  11 160  52 5046       L1_set Idle_NotYetReleased (iScriptState=LS_ENDINGCALL)
    Line 249964: 121042.819  11 160  52 5046       CallData.dateCallStartTime=2020-10-23 12:10:11, CallAnswerTime=2020-10-23 12:10:15, CallEndTime=2020-10-23 12:10:42
    Line 249965: 121042.819  11 160  52 5046       CDR_UpdateDetailsAndSaveTologs sCallDirection out
    Line 249966: 121042.819  11 160  52 5046       CDR_UpdateDetailsAndSaveTologs set LastCall
    Line 249967: 121042.819  11 160  52 5046       rv    add   CallHangupTime|2020-10-23 12:10:42
    Line 249968: 121042.819  11 160  52 5046       CDR_UpdateDetailsAndSaveTologs set strRVsXml
    Line 249969: 121042.819  11 160  52 5046       WriteCDRlogs: begin (campaign=, CallData.iLineId=160)
    Line 249970: 121042.819  11 160  52 5046       writing CDR logs

this disconnection occurs in the process for no reason

 

 

[Lukas]

we have a version vgEngine : 7.6.5 - 7.6.6977.23886

[SupportTeam]

Looks like the command to hangup the call was issued from one of the "Run VBScript" type modules.

Do you have any VBScripts/JavaScripts running in the callflow that handled the call on port 14 (and started the outgoing call leg on port 52) ? ie. after doing the bridged transfer do you have the callflow on port 14 move on and do and periodic calls to any VBScripts/JavaScripts modules?

If you can post the entire vgEngine trace excerpt for 3 seconds from 12:10:40 till 12:10:43. We can then see what VBScripts/JavaScript issues that command, and maybe why.

[Lukas]

Hi,

in the attachment log from channel 14

vg_hangin_up.rar

[SupportTeam]

Please post the post the entire vgEngine trace excerpt for 3 seconds from 12:10:40 till 12:10:43.

Not filtered by port number.

[Lukas]

in attachment

vg_hangin_up2.rar

[SupportTeam]

At 12:10:42.764 a callflow running on port 11 executed a "Run VBscript" module titled: "pbx_client_terminating_agent"

In that VBScript there is a line:

vg.Line_Hangup $RV[active_agent_line]

and the value of $RV[active_agent_line] on port 11 was set to "160". 160 is the "LineID" of port 52. (LineID is shown in the column preceding the Port Number in the vgEngine traces).

So when this VBScript was ran, the command was issued to hangup port 52.

Looking through the vgEngine trace should let you establish why $RV[active_agent_line] was set to a value of 160 on port 11. Perhaps port 11 had a connection to port 52 beforehand and the callflow was just not programmed to clear the $RV[active_agent_line] setting after that connection was ended?

If you do vgEngine trace extract filtered for port 11 you should be able to see what $RVs were set when. Also, if you can post this extract here, then we can then confirm at what stage the callflow should be clearing $RV[active_agent_line] value. It sounds like this callflow should be modified so it stops storing old data referencing ports once they re no longer used.

 

Relevant trace excerpt showing module "pbx_client_terminating_agent" issuing the "Line_Hangup" command:

121042.764   7  35  11 4835 state [pbx_client_terminating_agent] RunScript vbs, onhold=| : display not set as L2=Running_AfterHangup
121042.764   7  35  11 4835       rv    replace start
------------------------------
set vg = CreateObject("vgServices.CommandLink")
vg.Line_Hangup $RV[active_agent_line]

set vg = Nothing

------------------------------
121042.765   7  35  11 4835       rv    replace end   
------------------------------
set vg = CreateObject("vgServices.CommandLink")
vg.Line_Hangup 160

set vg = Nothing

------------------------------
121042.765   7  35  11 4835       scr   will be waiting. wait=1, calling iModuleIdx=676 (setting iRunWait_VgmIdx to 676)
121042.765   7  35  11 4835       moh not set
121042.765   7  35  11 4835       scr savescr_offline call
121042.765   7  35  11 4835       scr savescr_offline returned
121042.765   5  35  11 4835       vbs savescr_offline begin : C:\Program Files (x86)\VoiceGuide\temp\vbs_35_5.vbs
121042.765   7  35  11 4835       scr   ClearScript VBS engine used
121042.765   7  35  11 4835       scr   ClearScript VBS new VBScriptEngine completed
121042.765   5  35  11 4835       vbs savescr_offline script saved C:\Program Files (x86)\VoiceGuide\temp\vbs_35_5.vbs
121042.765   7  35  11 4835       scr   ClearScript VBS AddHostObject vg completed
121042.765   7  35  11 4835       scr   .Execute call
121042.766   4              rem   vgServices_CommandLink started
121042.768   4              rem   Line_Hangup 160
121042.768   4 160  52 5046       q_scr +     cmdHangupCall 0
121042.768  11 160  52 5046       q_scr run   cmdHangupCall 0  action_id=0, crn=0 [0|0|0|0|0][CommandLink|||||] 00:00:00 max:5|22,0013