Severe issue about TCL-scripting on AS5400XM

Version 1
    This document was generated from CDN thread

    Created by: Anton Eltyshev on 09-04-2011 01:52:23 AM
    Hello all.
    Initially I posted this message in the support community, but then I was suggested to put it here. Will appreciate any reply.
     
      For the last 2 years I'm facing a serious problem about TCL on as5400xm. I have two of that access servers so I can say, it is not about particular server, but common IOS issue. It took me months of traces to pinpoint where it happens and now I do need community help
     
      Here comes the description. I'm using a small TCL script to provide subscripers with the prepaid card telephony feature. They place calls to the number (incoming pots dial-peer) with the service defined on it. Service authenticates a subscriber and gives standard "enter destination" prompts. Then it places a call. Here the problem starts: calling subscriber doesn't hear neither ringback tones nor any voice even after called party answers the call. Meantime called party DO hears calling subscriber. The most interesting part of the bug is that after some time (from 2 up to 35+ seconds) voice channel gets normal, so that both parties can hear each other! However people normally just don't wait so long and drop the call.
      I found that this "one way audio issue" happens if there is any "media play" operator used before "leg setup". In other words, if there are no prompts to be played, then both call legs will be bridged with no problems. This workaround is not applicable, as you understand.  I tried a lot of IOS versions of the 12.4 branch and finally I found 12.4(15)T1 which does not have the bug. However there are some other issues about that version which make me look for a newer one (e.g. "fax rate disable" is not available in it). So I kindly ask for any help in resolving my problem, as it is very annoying and seems to be out of my understanding of how to get rid of it. The TCL script is attached.
     
    P.S. I do know about CSCsr60092, but this is not the case.
     
    P.P.S. I tried "debug voice app all" but there are NO events registered at the moment when voice channel gets normal.

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Raghavendra Gutty Veeranagappa on 11-04-2011 03:06:16 AM
    Hi Anton,

    Please send us the logs by enabling following debugs and also please let us know the IOS version your facing the issue.

    Debug voip app all
    Debug voip ccapi all
    Debug voip rtp

    Thanks,
    Raghavendra

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Anton Eltyshev on 11-04-2011 05:15:22 AM
    Please find another log. In this case it took 1 minute 20 seconds for
    the voice channel to get two-way. What is important - I don't see any
    corresponding event in the trace at the moment when called party gets
    normally heared. Again I'd like to highlight: there are no ringback tones when alert message comes from the remote side.


    Hi Anton,

    Please send us the logs by enabling following debugs and also please let us know the IOS version your facing the issue.

    Debug voip app all
    Debug voip ccapi all
    Debug voip rtp

    Thanks,
    Raghavendra

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Raghavendra Gutty Veeranagappa on 11-04-2011 05:33:52 AM
    Hi IIya,

    thanks for sharing the logs,

    i could'nt find ev_collectdigits_done event and leg setup issued by script in the logs, but the script received ev_setup_done event not sure how it happens, could you please explain breifly about your  call flow.

    Thanks,
    raghavendra

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Anton Eltyshev on 11-04-2011 07:08:16 AM
    I have cleaned the thread a bit due to the banch of duplicates...
     
    I'm also surprised that there are no events which you mention. The flow of that call is as follows:
     
    1. The call comes to the application
    2. Application answers the call with leg setupack
    3. Application authorizes a caller side with aaa authorize
    4.1 If it's ok (ao_000), then app starts with digit collection:
          set pattern(1) {810.+}
          set pattern(2) {8[3456789].........}
          leg collectdigits leg_incoming ParamForCall pattern
    4.2 And at the same place app plays "Enter destination" prompt:
          media play leg_incoming flashrompts/enter_destination.wav
    5. After ev_collectdigits_done, app executes
          leg setup $dest callInfo leg_incoming
     
    Let me know if you need the full explanation on the script behaviour.
     
    By the way, I have just written VERY simple TCL-script, doing two things:
    1. Plays message
    2. Places call
     
      Same problem happens in it!!! But once I remove media play, it works fine! There is definetely something wrong about media playback! Below I put the script that I've mentioned:
     
    #-----
    proc init { } {
        global param
        set param(interruptPrompt) true
        set param(abortKey) *
        set param(terminationKey) #
    }

    proc act_Setup { } {
        global dest
        global args
        global callInfo

        set callInfo(speech) true
        set callInfo(originationNum) "8612170985"
          set dest "79184442244"
           leg setupack leg_incoming
           media play leg_incoming flashrompts/enter_destination.wav
           fsm setstate PLAYINGPROMPT
    }

    proc act_ConnectAfterPrompt { } {
        global dest
        global callInfo
       
        leg setup $dest callInfo leg_incoming
          fsm setstate PLACECALL
    }

    proc act_CallSetupDone { } {
        global beep
        global incoming
        global outgoing
       
        set status [infotag get evt_status]
        set incoming [infotag get leg_incoming]
        set outgoing [infotag get leg_outgoing]

        if {$status == "ls_000"} {
          #puts "CALL IS OK"
          return
        }
        if {$status == "ls_007"} {
             leg disconnect_prog_ind leg_incoming -c17 -p8
             call close
           } else {
          call close
        }
    }

    proc act_Cleanup { } {
        call close
    }

    init

    #----------------------------------
    #   State Machine
    #----------------------------------
      set fsm(any_state,ev_disconnected)         "act_Cleanup same_state"
      set fsm(CALL_INIT,ev_setup_indication)     "act_Setup GETDEST"
      set fsm(PLAYINGPROMPT,ev_media_done)       "act_ConnectAfterPrompt same_state"
      set fsm(PLACECALL,ev_setup_done)           "act_CallSetupDone CALLACTIVE"
      set fsm(CALLACTIVE,ev_disconnected)        "act_Cleanup CALLDISCONNECT"
      set fsm(CALLDISCONNECT,ev_disconnected)    "act_Cleanup same_state"
      set fsm(CALLDISCONNECT,ev_media_done)      "act_Cleanup same_state"
      set fsm(CALLDISCONNECT,ev_disconnect_done) "act_Cleanup same_state"
      set fsm(CALLDISCONNECT,ev_leg_timer)       "act_Cleanup same_state"
      fsm define fsm CALL_INIT
     

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Anton Eltyshev on 11-04-2011 04:25:53 AM
    Hello
     
      Thank you for your response.

      Please find the requested logs attached. Regarding IOS version, as I said, I don't face the problem in 12.4(15)T1, and face it in all the rest tested. At this moment I have 12.4(25e) installed - the latest one as I understand: Cisco IOS Software, 5400 Software (C5400-JS-M), Version 12.4(25e), RELEASE SOFTWARE (fc2).
      For the call that is logged, voice channel got normal at ~5-7 second after the answer. The overall duration was about 10 seconds.
     
    Regards,
     
    Ilya.

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Raghavendra Gutty Veeranagappa on 11-04-2011 08:31:15 AM
    Hi IIya,

    looks like your are hitting CSCsr60092 issue, please try to configure following command and let us know if it resolves your issue.

    Syntax:
    router(config)#no voice session-handle enable

    Thanks,
    Raghavendra

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Anton Eltyshev on 11-04-2011 08:56:11 AM
    Raghavendra , you are my hero! I'm still testing, but from the first look it seems your workaround is working!

    But I don't understand following:

    1. I tried those IOS versions that are mentioned on bug toolkit as "fixed in" for the CSCsr60092 issue. Those versions didn't help in my case. Why?
    2. I would never bothered people, if I knew there is workaround, but again - on Bug toolkit it is clearly stated "There is no workaround" for that bug.

    I will continue my tests, but anyway, today I got the biggest progress in this issue since I first time faced it. Thank you very much, I will update this thread with results. And I would very appreciate if you explain what "no voice session-handle enable" command really does.

    Thanks again.

    Regards,

    Ilya

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Anton Eltyshev on 11-04-2011 09:25:24 AM
    I have also found, this command is not saved with "write" command, so after router have restarted, I have to re-enter it into configuration. Is that a correct behaviour?

    Regards,

    Ilya.

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Raghavendra Gutty Veeranagappa on 11-04-2011 09:46:50 AM
    Hi IIya,

    This is internal CLI Command ,the workaround for the one way audio issue in as5400. no need to reconfigure i guess when you restart the router.

    Thanks,
    Raghavendra

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Anton Eltyshev on 11-04-2011 09:59:26 AM
    Hi IIya,

    This is internal CLI Command ,the workaround for the one way audio issue in as5400. no need to reconfigure i guess when you restart the router.

    Thanks,
    Raghavendra

     
    I have just checked: it does need reconfiguration, since after restart the command disappears from the configuration. But this is not a big deal taking into account that after the command as5400xm works OK! Do you think I faced a new "version" of the CSCsr60092 bug? I mean, that according to the bug toolkint it is considered fixed.
     
    Thanks,
     
    Ilya.

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Anton Eltyshev on 11-04-2011 01:09:33 PM
    Raghavendra, I have faced another weird thing. I have got 2 (two) as5400xm. On both of them I installed the latest T release of IOS that I have. It is 12.4(22)T4. Again - I have just installed that IOS on both of them and have reloaded both of them. Both are ok, up and running, BUT: on one I can enter "no voice session-handle enable" command, and on another - I can not! The answer is

    AS5400XM(config)#no voice session-handle enable
                                              ^
    % Invalid input detected at '^' marker.

    There are only two differences between those as5400xm:

    1. Different boot strap versions

    2. Different number of nextport modules.

    Would you please explain what makes as5400xm not to accept the command? Same router, same IOS - different behaviour.

    Thanks in advance.

    P.S. I'm getting crazy of all these things happening about two my access servers.

    Regards.

    Subject: RE: Severe issue about TCL-scripting on AS5400XM
    Replied by: Anton Eltyshev on 11-04-2011 01:38:46 PM
    Well, I found another undocumented command "service internal". After I executed it, "no voice session-handle enable" was accepted OK.