IVR timing bug WaitExten()

[luckman212]

Help! My IVR is trapping people in limbo!

edit: apparently I'm not the only one experiencing this bug! so it looks like for now I will have to hand-edit the IVR contexts until it's fixed. Not sure if the bug is Asterisk or FreePBX but I don't know if the 2.9beta has changed the way the IVRs are generated. Can anyone confirm??

I didn't even realize this was happening until a few of my friends told me they got stuck in the IVR waiting forever. Not sure how long this has been going on for to be honest so it could be weeks, months. PIAF purple 32bit 1.7.5.5 running 1.8.3.2 (now running SVN actually) using DAHDI timers with a sangoma UT50 source, my hardware clocksource is acpi_pm, and CPU is Atom 230 (acer aspire revo).

here's some more info:

pbx*CLI> module show like timing
Module                         Description                              Use Count 
res_timing_dahdi.so            DAHDI Timing Interface                   2         
res_timing_pthread.so          pthread Timing Interface                 0         
2 modules loaded

root@pbx:~ $ /etc/rc.d/init.d/dahdi status
### Span  1: WANVTIME/1 "WANVTIME/1 (source: wanpipe_voicetime) 1" (MASTER)

so here's the verbose CLI output during one of these failed calls. You can see that the last line is WaitExten(,) which just sits forever. If the caller actually does press '0' even after waiting like 5 minutes then the call does ring my phone, so the IVR is still working, it's just the 't' timeout never triggers. Has anyone else seen or experienced this??

  == Using UDPTL TOS bits 184
  == Using UDPTL CoS mark 5
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Executing [12125551212@from-trunk-custom:1] GotoIf("SIP/mytrunk-00000010", "0?noplusatstart") in new stack
    -- Executing [12125551212@from-trunk-custom:2] NoOp("SIP/mytrunk-00000010", "Changing Caller ID number from +13334567890 to 3334567890") in new stack
    -- Executing [12125551212@from-trunk-custom:3] Set("SIP/mytrunk-00000010", "CALLERID(num)=3334567890") in new stack
    -- Executing [12125551212@from-trunk-custom:4] Set("SIP/mytrunk-00000010", "CALLERID(ANI-num)=3334567890") in new stack
    -- Executing [12125551212@from-trunk-custom:5] Goto("SIP/mytrunk-00000010", "from-trunk,12125551212,1") in new stack
    -- Goto (from-trunk,12125551212,1)
    -- Executing [12125551212@from-trunk:1] NoOp("SIP/mytrunk-00000010", "Catch-All DID Match - Found 12125551212 - You probably want a DID for this.") in new stack
    -- Executing [12125551212@from-trunk:2] Goto("SIP/mytrunk-00000010", "ext-did,s,1") in new stack
    -- Goto (ext-did,s,1)
    -- Executing [s@ext-did:1] Set("SIP/mytrunk-00000010", "__FROM_DID=s") in new stack
    -- Executing [s@ext-did:2] Gosub("SIP/mytrunk-00000010", "cidlookup,cidlookup_3,1") in new stack
    -- Executing [cidlookup_3@cidlookup:1] Set("SIP/mytrunk-00000010", "CALLERID(name)=John Smith") in new stack
    -- Executing [cidlookup_3@cidlookup:2] Return("SIP/mytrunk-00000010", "") in new stack
    -- Executing [s@ext-did:3] Gosub("SIP/mytrunk-00000010", "app-blacklist-check,s,1") in new stack
    -- Executing [s@app-blacklist-check:1] GotoIf("SIP/mytrunk-00000010", "0?blacklisted") in new stack
    -- Executing [s@app-blacklist-check:2] Set("SIP/mytrunk-00000010", "CALLED_BLACKLIST=1") in new stack
    -- Executing [s@app-blacklist-check:3] Return("SIP/mytrunk-00000010", "") in new stack
    -- Executing [s@ext-did:4] ExecIf("SIP/mytrunk-00000010", "0 ?Set(CALLERID(name)=3334567890)") in new stack
    -- Executing [s@ext-did:5] SetMusicOnHold("SIP/mytrunk-00000010", "stream") in new stack
    -- Executing [s@ext-did:6] Set("SIP/mytrunk-00000010", "__MOHCLASS=stream") in new stack
    -- Executing [s@ext-did:7] Ringing("SIP/mytrunk-00000010", "") in new stack
    -- Executing [s@ext-did:8] Wait("SIP/mytrunk-00000010", "1") in new stack
    -- Executing [s@ext-did:9] Set("SIP/mytrunk-00000010", "__CALLINGPRES_SV=allowed_not_screened") in new stack
    -- Executing [s@ext-did:10] Set("SIP/mytrunk-00000010", "CALLERPRES()=allowed_not_screened") in new stack
    -- Executing [s@ext-did:11] Goto("SIP/mytrunk-00000010", "app-daynight,0,1") in new stack
    -- Goto (app-daynight,0,1)
    -- Executing [0@app-daynight:1] GotoIf("SIP/mytrunk-00000010", "0?ext-group,778,1:ivr-4,s,1") in new stack
    -- Goto (ivr-4,s,1)
    -- Executing [s@ivr-4:1] Set("SIP/mytrunk-00000010", "MSG=custom/welcome-1&custom/if-you-know-your-partys-ext") in new stack
    -- Executing [s@ivr-4:2] Set("SIP/mytrunk-00000010", "LOOPCOUNT=0") in new stack
    -- Executing [s@ivr-4:3] Set("SIP/mytrunk-00000010", "__DIR-CONTEXT=") in new stack
    -- Executing [s@ivr-4:4] Set("SIP/mytrunk-00000010", "_IVR_CONTEXT_ivr-4=") in new stack
    -- Executing [s@ivr-4:5] Set("SIP/mytrunk-00000010", "_IVR_CONTEXT=ivr-4") in new stack
    -- Executing [s@ivr-4:6] GotoIf("SIP/mytrunk-00000010", "0?begin") in new stack
    -- Executing [s@ivr-4:7] Answer("SIP/mytrunk-00000010", "") in new stack
    -- Executing [s@ivr-4:8] Wait("SIP/mytrunk-00000010", "1") in new stack
    -- Executing [s@ivr-4:9] Set("SIP/mytrunk-00000010", "TIMEOUT(digit)=3") in new stack
    -- Digit timeout set to 3.000
    -- Executing [s@ivr-4:10] Set("SIP/mytrunk-00000010", "TIMEOUT(response)=2") in new stack
    -- Response timeout set to 2.000
    -- Executing [s@ivr-4:11] Set("SIP/mytrunk-00000010", "__IVR_RETVM=") in new stack
    -- Executing [s@ivr-4:12] ExecIf("SIP/mytrunk-00000010", "1?Background(custom/welcome-1&custom/if-you-know-your-partys-ext)") in new stack
    -- <SIP/mytrunk-00000010> Playing 'custom/welcome-1.slin' (language 'en')
    -- <SIP/mytrunk-00000010> Playing 'custom/if-you-know-your-partys-ext.slin' (language 'en')
    -- Executing [s@ivr-4:13] WaitExten("SIP/mytrunk-00000010", ",") in new stack                 [B][COLOR="Red"]<===== hangs here forever (I do mean forever, until party hangs up[/COLOR][/B])

 

[luckman212]

Ok, I found the bug and made a patch.

here you go:
edit /var/www/html/admin/modules/ivr/functions.inc.php

find this line:
$ext->add($id, 's', '', new ext_waitexten());

change to:
$ext->add($id, 's', '', new ext_waitexten($details['timeout']));

save, and then re-save your IVRs and apply.
not tested too much but seems to do the trick for me

 

[jmullinix]

Did you post the bug in the FreePBX bugtracker?

 

[luckman212]

I don't know yet if this is a FreePBX bug or an Asterisk one. Leaning towards it being an Asterisk bug at this point since when written out as WaitExten(,) it does work *sometimes* and then mysteriously it will stop working. I think the way WaitExten was supposed to work was it was supposed to honor the $TIMEOUT(response) variable in absence of a fixed number-- but somehow, somewhere that $TIMEOUT variable is getting set wrong, not released, or set with a bogus value causing the dialplan to just sit there indefinitely.