TCL Error when runing [infotag get evt_handoff dnis]

Hello Guys

I have a test 2900 CME router with Cisco IOS Software, C2900 Software (C2900-UNIVERSALK9-M), Version 15.1(4)M4, RELEASE SOFTWARE (fc1),  I have been working for a couple of weeks with a TCL script to gather and authenticate callpin codes.  Everything runs great when doing my tests.  However when I move the script to the production CME router that has Cisco IOS Software, C2900 Software (C2900-UNIVERSALK9-M), Version 15.3(3)M, RELEASE SOFTWARE (fc2) and configure it, nothing works and I start having errors.

I start getting this error:

*Jul 16 16:49:19.103: //139148//TCL :/tcl_InfotagObjCmd:  infotag get leg_ani

*Jul 16 16:49:19.103: //139148//TCL :/tcl_InfotagGetObjCmd: infotag get leg_ani

*Jul 16 16:49:19.103: //139148//AFW_:/vtr_lg_ani: argc 2 argindex 2

*Jul 16 16:49:19.103: //139148//TCL :/tcl_InfotagObjCmd:  infotag get evt_handoff dnis

*Jul 16 16:49:19.103: //139148//TCL :/tcl_InfotagGetObjCmd: infotag get evt_handoff dnis

*Jul 16 16:49:19.103: //139148//AFW_:/vtr_ev_handoff: argc 3 argindex 2UpdateStringProc should not be invoked for type

After that last message with the  UpdateStringProc error, nothing more happens for that script. I saw a post (by Paolo Bevilaqua) that complained about the same problem with a 15.2 version of the software. But no recommendation whatsoever

Any pointer on what can I do to identify what is going on and fix it?

Thanks in advance!

HI,

could you please share the logs with below debugs.

debug voip app

Thanks,

Raghavendra

Hello,

Attached is the log from the router.

What I did is first reload the app so you could see which events are being triggered.  Then make a call to a local cell 80991466601 that activates the dial-peer voice 9001 with this configuration:

dial-peer voice 9001 voip

service fac_celular out-bound

destination-pattern 809........

session protocol sipv2

session target loopback:rtp

The script always hangs on the same part:

*Jul 21 14:08:28.714: //141261//Call:/AFW_CallSetup_Continue:

*Jul 21 14:08:28.714: //141261//Dest:/AFW_Destination_Continue:

*Jul 21 14:08:28.726: //141261//TCL :/tcl_InfotagObjCmd:  infotag get evt_handoff dnis

*Jul 21 14:08:28.726: //141261//TCL :/tcl_InfotagGetObjCmd: infotag get evt_handoff dnis

*Jul 21 14:08:28.726: //141261//AFW_:/vtr_ev_handoff: argc 3 argindex 2UpdateStringProc should not be invoked for type    <== right here!

*Jul 21 14:09:05.870: //-1//AFW_:/AFW_Event_New: Event ID: ev_any_event(0)

*Jul 21 14:09:05.870: //141261//AFW_:/AFW_Process_GetCcqEvent: Received

*Jul 21 14:09:05.870: //-1//AFW_:/AFW_Process_GetCcqEvent:   Event[CC_EV_CALL_DISCONNECT_NOTIFY(23)] {

And nothing happens until I close the call. It just stays there.

I am also attaching the script.

I have tested this script with other routers and it works with other versions of IOS.  I have even started deployment on one production system.

Best regards.

could you please set directly number to dnis instead of below code and see everything works.

set dnis [infotag get evt_handoff dnis]

The logs are incomplete, Please use "logging buffer 10000000" and "no logging console" configuration.

Please collect the logs with below debugs and also explain your call flow to understand the issue better.

debug voip app

debug ccsip messages

debug voip ccapi all

Thanks,

Raghavendra

Hello Raghavendra,

I changed the code to set the dnis variable to a hardcoded value (123), and the script flows normally (that is, plays the media on the leg, and capture the digits.)

Also I tried changing the line to "puts [infotag get evt_handoff dnis]"  and the very same error show up on the log "UpdateStringProc should not be invoked for type".  When this error shows, the have done some random weird stuff, like loosing connectivity (loose ping packets), or closing the ssh sesion.  Also If I don't end the call, the phone call just stays there waiting.

I think it definitely has something to with this "infotag get evt_handoff dnis" function.

Attached is the log with all the settings you said. 

Thank you for testing and sharing the logs, i will check with DE team on this issue and update you.

could you please try with latest image and see if issue is resolved.

Thanks,

Raghavendra

I upgraded to the lates IOS 15.4 and the bug is still there on the very same function call. now the debug show more info, but this image does not work for me, I will try latest 15.2 next.

Jul 25 02:14:01.089: //20//TCL :/tcl_InfotagGetObjCmd: infotag get evt_handoff dnis

Jul 25 02:14:01.089: //20//AFW_:/vtr_ev_handoff: argc 3 argindex 2UpdateStringProc should not be invoked for type

Jul 25 02:14:28.801: %SRE_SM-6-STATE_CHANGE: ISM0/0 changing state from SERVICE_MODULE_STATE_STDY to SERVICE_MODULE_STATE_WREG

Jul 25 02:14:28.813: %SRE_SM-6-STATE_CHANGE: ISM0/0 changing state from SERVICE_MODULE_STATE_WREG to SERVICE_MODULE_STATE_STDY

Jul 25 02:14:30.721: efxs_onhook_offhook: call is already reserved on htsp 50/0/25.1 cdb 0x3FF338D8

Jul 25 02:14:59.536: %ALIGN-3-SPURIOUS: Spurious memory access made at 0x33270E30z  reading 0x4

Jul 25 02:14:59.536: %ALIGN-3-TRACE: -Traceback= 0x33270E30z 0x35A586ACz 0x35A65E58z 0x35A647C0z 0x3324F314z 0x33252F78z 0x3322FAA8z 0x3324CFB4z

Jul 25 02:14:59.536: %ALIGN-3-TRACE: -Traceback= 0x33270E3Cz 0x35A586ACz 0x35A65E58z 0x35A647C0z 0x3324F314z 0x33252F78z 0x3322FAA8z 0x3324CFB4z

Jul 25 02:14:59.536: %ALIGN-3-TRACE: -Traceback= 0x33270E40z 0x35A586ACz 0x35A65E58z 0x35A647C0z 0x3324F314z 0x33252F78z 0x3322FAA8z 0x3324CFB4z

Jul 25 02:14:59.536: %ALIGN-3-TRACE: -Traceback= 0x33270E4Cz 0x35A586ACz 0x35A65E58z 0x35A647C0z 0x3324F314z 0x33252F78z 0x3322FAA8z 0x3324CFB4z

Update...

15.2 does not work either!

I am going down to 15.1(4), the one that I have tested it works on my other router.

Finally 15.1(4) works.

thanks for the update, i understand with 15.1(4) it works but it is not working with 15.2 and 15.3 we will look into this issue.

Thanks,

Raghavendra

Final status is:

15.1 Works

15.2 Fails

15.3 Fails

15.4 Fails

Best regards.

I thought I was going to be fine for a while, because the 15.1 IOS image works with my script.  But now I want to implement multiple destination patterns with a single Dial Peer, and guess what... The version needed to implement this is 15.2!

I guess I will have to wait and see if anyone picks this one up...

i have raised bug ( CSCuq34654 ) for this issue, DE team is working on it.

Thanks,

Raghavendra

DE Team fixed the issue, fix will be available in 15.3(3)M and 15.4(3)M releases.

Thanks,

Raghavendra