[Home]

Summary:ASTERISK-03993: Global variables do not get set when called from a macro by Dial application
Reporter:Chris Hozian (chozian)Labels:
Date Opened:2005-04-26 18:40:16Date Closed:2005-04-29 10:22:23
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:I noticed that in Asterisk CVS-HEAD-04/26/05-17:54:51 global variables are not getting set properly from a macro called by the Dial application.  This problem may be present in standard macros.  Though I have not tested that.

In the macro-screen I set BYPASSVM to 1 if the call is accepted.  Though NoOp shows the variable as still equaling 0.

This problem did not exist right before I did a CVS update.  I was running a CVS version from about 2 and a half weeks ago.  I don't remember the exact version that I was running previously.  I made absolutely no changes before upgrading.  Immediately after upgrading this problem started.

I added the NoOp to display the BYPASSVM variable at various points.

Here is out my dialplan.  
 
[incoming]
exten => s,1,SetGlobalVar(BYPASSVM=0)
exten => s,n,Setvar(INVALIDTRIES=0)
exten => s,n,ResponseTimeout(30)
exten => s,n,SetMusicOnHold(random)
exten => s,n,Answer

exten => s,n,NoOp(${BYPASSVM})

exten => s,n,NoOp(${CALLERID})
exten => s,n(recordagain),Wait(2)
exten => s,n,Playback(pls-rcrd-name-at-tone)
exten => s,n,Playback(and-prs-pound-whn-finished)
exten => s,n,SetVar(SCREEN_FILE=/tmp/${TIMESTAMP}-${CALLERIDNUM})
exten => s,n,Record(${SCREEN_FILE}.gsm|6|25)
exten => s,n,Wait(1)
exten => s,n,Playback(${SCREEN_FILE})
exten => s,n(returnfrominvalid),Wait(1)
exten => s,n,Playback(press-1)
exten => s,n,Playback(to-accept-recording)
exten => s,n,Playback(or)
exten => s,n,Playback(press-2)
exten => s,n,Read(ACCEPTRECORD|to-rerecord-yr-message|1)
exten => s,n,GotoIf($["${ACCEPTRECORD}" = ""] ?t,1)
exten => s,n,GotoIf($[${ACCEPTRECORD} = 1] ?callaccepted)
exten => s,n,GotoIf($[${ACCEPTRECORD} = 2] ?recordagain:i,1)
exten => s,n(callaccepted),Wait(1)
exten => s,n,Playback(this-call-may-be-monitored-or-recorded)
exten => s,n,Wait(1)
exten => s,n,Playback(pls-hold-while-try)
exten => s,n,Dial(${FWDRINGS},60,gmM(screen^${SCREEN_FILE}))
exten => s,n,GotoIf($[${BYPASSVM} = 1] ?hangup)

exten => s,n,NoOp(${BYPASSVM})

exten => s,n,Voicemail(u${FWDVMBOX})
exten => s,n(hangup),Hangup
exten => i,1,GotoIf($[${INVALIDTRIES} = 4] ?t,1)
exten => i,n,Playback(invalid)
exten => i,n,Setvar(INVALIDTRIES=$[${INVALIDTRIES} + 1])
exten => i,n,Goto(returnfrominvalid)
exten => t,1,System(/bin/rm ${SCREEN_FILE}.gsm)
exten => t,n,Playback(call-terminated)
exten => t,n,Playback(goodbye)
exten => t,n,Hangup
exten => h,1,System(/bin/rm ${SCREEN_FILE}.gsm)

[macro-screen]
exten => s,1,Wait(1)
exten => s,n,Playback(call)
exten => s,n,Playback(from)
exten => s,n,Playback(${ARG1})
exten => s,n(repeatagain),Wait(1)
exten => s,n,Playback(press-1)
exten => s,n,Playback(for)
exten => s,n,Playback(pbx-transfer)
exten => s,n,Playback(or)
exten => s,n,Playback(press-9)
exten => s,n,Read(ACCEPTCALL|to-hang-up|1)
exten => s,n,GotoIf($["${ACCEPTCALL}" = ""] ?t,1)
exten => s,n,GotoIf($[${ACCEPTCALL} = 1] ?callaccepted)
exten => s,n,GotoIf($[${ACCEPTCALL} = 9] ?calldenied:repeatagain)
exten => s,n(calldenied),SetVar(MACRO_RESULT=CONTINUE)
exten => s,n,GotoIf($[${MACRO_RESULT} = CONTINUE] ?skipmonitor)
exten => s,n(callaccepted),SetGlobalVar(BYPASSVM=1)

exten => s,n,NoOp(${BYPASSVM})

exten => s,n,Wait(1)
exten => s,n,Playback(this-call-may-be-monitored-or-recorded)
exten => s,n,Monitor(wav49|${TIMESTAMP}-${CALLERID}|mb)
exten => s,n(skipmonitor),System(/bin/rm ${ARG1}.gsm)
exten => t,1,Playback(connection-timed-out)
exten => t,n,Goto(s,calldenied)


Here is my debug output.
 
 == Parsing '/etc/asterisk/asterisk.conf': Found
 == Parsing '/etc/asterisk/extconfig.conf': Found
Asterisk CVS-HEAD-04/26/05-17:54:51, Copyright (C) 1999 - 2005 Digium.
Written by Mark Spencer <markster@digium.com>
=========================================================================
Connected to Asterisk CVS-HEAD-04/26/05-17:54:51 currently running on naibed (pid = 16472)
Verbosity is at least 3
Apr 26 18:28:50 DEBUG[16473]: acl.c:195 ast_apply_ha: ##### Testing 192.168.100.57 with 192.168.100.57
   -- Accepting AUTHENTICATED call from 192.168.100.57:
      > requested format = ulaw,
      > requested prefs = (),
      > actual format = ulaw,
      > host prefs = (ulaw),
      > priority = mine
   -- Executing Goto("IAX2/njtest@tonjtest-6", "incoming|s|1") in new stack
   -- Goto (incoming,s,1)
   -- Executing SetGlobalVar("IAX2/njtest@tonjtest-6", "BYPASSVM=0") in new stack
   -- Setting global variable 'BYPASSVM' to '0'
   -- Executing SetVar("IAX2/njtest@tonjtest-6", "INVALIDTRIES=0") in new stack
   -- Executing ResponseTimeout("IAX2/njtest@tonjtest-6", "30") in new stack
   -- Set Response Timeout to 30
   -- Executing SetMusicOnHold("IAX2/njtest@tonjtest-6", "random") in new stack
   -- Executing Answer("IAX2/njtest@tonjtest-6", "") in new stack
   -- Executing NoOp("IAX2/njtest@tonjtest-6", "0") in new stack
   -- Executing NoOp("IAX2/njtest@tonjtest-6", ""NJ Test" <6001>") in new stack
   -- Executing Wait("IAX2/njtest@tonjtest-6", "2") in new stack
Apr 26 18:28:50 DEBUG[16473]: chan_iax2.c:6478 socket_read: Ooh, voice format changed to 4
   -- Executing Playback("IAX2/njtest@tonjtest-6", "pls-rcrd-name-at-tone") in new stack
Apr 26 18:28:52 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'pls-rcrd-name-at-tone' (language 'en')
Apr 26 18:28:54 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:28:54 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("IAX2/njtest@tonjtest-6", "and-prs-pound-whn-finished") in new stack
Apr 26 18:28:54 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'and-prs-pound-whn-finished' (language 'en')
Apr 26 18:28:56 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:28:56 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing SetVar("IAX2/njtest@tonjtest-6", "SCREEN_FILE=/tmp/20050426-182856-6001") in new stack
   -- Executing Record("IAX2/njtest@tonjtest-6", "/tmp/20050426-182856-6001.gsm|6|25") in new stack
Apr 26 18:28:56 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'beep' (language 'en')
Apr 26 18:28:56 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:28:56 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Wait("IAX2/njtest@tonjtest-6", "1") in new stack
   -- Executing Playback("IAX2/njtest@tonjtest-6", "/tmp/20050426-182856-6001") in new stack
Apr 26 18:28:58 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing '/tmp/20050426-182856-6001' (language 'en')
Apr 26 18:28:59 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:28:59 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Wait("IAX2/njtest@tonjtest-6", "1") in new stack
   -- Executing Playback("IAX2/njtest@tonjtest-6", "press-1") in new stack
Apr 26 18:29:00 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'press-1' (language 'en')
Apr 26 18:29:01 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:01 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("IAX2/njtest@tonjtest-6", "to-accept-recording") in new stack
Apr 26 18:29:01 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'to-accept-recording' (language 'en')
Apr 26 18:29:03 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:03 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("IAX2/njtest@tonjtest-6", "or") in new stack
Apr 26 18:29:03 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'or' (language 'en')
Apr 26 18:29:04 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:04 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("IAX2/njtest@tonjtest-6", "press-2") in new stack
Apr 26 18:29:04 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'press-2' (language 'en')
Apr 26 18:29:04 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:04 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Read("IAX2/njtest@tonjtest-6", "ACCEPTRECORD|to-rerecord-yr-message|1") in new stack
   -- Accepting a maximum of 1 digits.
Apr 26 18:29:04 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'to-rerecord-yr-message' (language 'en')
Apr 26 18:29:06 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:06 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- User entered '1'
Apr 26 18:29:08 DEBUG[16473]: pbx.c:1527 pbx_substitute_variables_helper_full: Expression is '0'
   -- Executing GotoIf("IAX2/njtest@tonjtest-6", "0 ?t|1") in new stack
Apr 26 18:29:08 DEBUG[16473]: pbx.c:5897 pbx_builtin_gotoif: Not taking any branch
Apr 26 18:29:08 DEBUG[16473]: pbx.c:1527 pbx_substitute_variables_helper_full: Expression is '1'
   -- Executing GotoIf("IAX2/njtest@tonjtest-6", "1 ?callaccepted") in new stack
   -- Goto (incoming,s,24)
   -- Executing Wait("IAX2/njtest@tonjtest-6", "1") in new stack
   -- Executing Playback("IAX2/njtest@tonjtest-6", "this-call-may-be-monitored-or-recorded") in new stack
Apr 26 18:29:09 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'this-call-may-be-monitored-or-recorded' (language 'en')
Apr 26 18:29:11 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:11 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Wait("IAX2/njtest@tonjtest-6", "1") in new stack
   -- Executing Playback("IAX2/njtest@tonjtest-6", "pls-hold-while-try") in new stack
Apr 26 18:29:12 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'pls-hold-while-try' (language 'en')
Apr 26 18:29:15 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:15 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Dial("IAX2/njtest@tonjtest-6", "Zap/g1|60|gmM(screen^/tmp/20050426-182856-6001)") in new stack
   -- Called g1
   -- Started music on hold, class 'random', on IAX2/njtest@tonjtest-6
Apr 26 18:29:15 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Zap/1-1 is ringing
Apr 26 18:29:15 DEBUG[16473]: channel.c:1505 ast_read: Generator got voice, switching to phase locked mode
Apr 26 18:29:15 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:16 DEBUG[16473]: chan_zap.c:4035 __zt_exception: Exception on 13, channel 1
Apr 26 18:29:16 DEBUG[16473]: chan_zap.c:3269 zt_handle_event: Got event Ring/Answered(2) on channel 1 (index 0)
Apr 26 18:29:16 DEBUG[16473]: chan_zap.c:1340 zt_enable_ec: Enabled echo cancellation on channel 1
Apr 26 18:29:16 DEBUG[16473]: chan_zap.c:1359 zt_train_ec: No echo training requested
Apr 26 18:29:16 DEBUG[16473]: chan_zap.c:3523 zt_handle_event: channel 1 answered
   -- Zap/1-1 answered IAX2/njtest@tonjtest-6
   -- Executing Wait("Zap/1-1", "1") in new stack
   -- Executing Playback("Zap/1-1", "call") in new stack
Apr 26 18:29:18 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'call' (language 'en')
Apr 26 18:29:18 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:18 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("Zap/1-1", "from") in new stack
Apr 26 18:29:18 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'from' (language 'en')
Apr 26 18:29:19 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:19 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("Zap/1-1", "/tmp/20050426-182856-6001") in new stack
Apr 26 18:29:19 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing '/tmp/20050426-182856-6001' (language 'en')
Apr 26 18:29:20 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:20 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Wait("Zap/1-1", "1") in new stack
   -- Executing Playback("Zap/1-1", "press-1") in new stack
Apr 26 18:29:21 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'press-1' (language 'en')
Apr 26 18:29:21 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:21 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("Zap/1-1", "for") in new stack
Apr 26 18:29:21 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'for' (language 'en')
Apr 26 18:29:22 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:22 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("Zap/1-1", "pbx-transfer") in new stack
Apr 26 18:29:22 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'pbx-transfer' (language 'en')
Apr 26 18:29:23 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:23 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("Zap/1-1", "or") in new stack
Apr 26 18:29:23 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'or' (language 'en')
Apr 26 18:29:23 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:23 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Playback("Zap/1-1", "press-9") in new stack
Apr 26 18:29:23 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'press-9' (language 'en')
Apr 26 18:29:24 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:24 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Read("Zap/1-1", "ACCEPTCALL|to-hang-up|1") in new stack
   -- Accepting a maximum of 1 digits.
Apr 26 18:29:24 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'to-hang-up' (language 'en')
Apr 26 18:29:25 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:25 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:27 DEBUG[16473]: chan_zap.c:4313 zt_read: DTMF digit: 1 on Zap/1-1
   -- User entered '1'
Apr 26 18:29:27 DEBUG[16473]: pbx.c:1527 pbx_substitute_variables_helper_full: Expression is '0'
   -- Executing GotoIf("Zap/1-1", "0 ?t|1") in new stack
Apr 26 18:29:27 DEBUG[16473]: pbx.c:5897 pbx_builtin_gotoif: Not taking any branch
Apr 26 18:29:27 DEBUG[16473]: pbx.c:1527 pbx_substitute_variables_helper_full: Expression is '1'
   -- Executing GotoIf("Zap/1-1", "1 ?callaccepted") in new stack
   -- Goto (macro-screen,s,18)
   -- Executing NoOp("Zap/1-1", "0") in new stack
   -- Executing Wait("Zap/1-1", "1") in new stack
   -- Executing Playback("Zap/1-1", "this-call-may-be-monitored-or-recorded") in new stack
Apr 26 18:29:28 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'this-call-may-be-monitored-or-recorded' (language 'en')
Apr 26 18:29:30 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:30 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Executing Monitor("Zap/1-1", "wav49|20050426-182930-s|mb") in new stack
   -- Executing System("Zap/1-1", "/bin/rm /tmp/20050426-182856-6001.gsm") in new stack
Apr 26 18:29:30 DEBUG[16473]: app_dial.c:1212 dial_exec_full: Macro exited with status 0
   -- Stopped music on hold on IAX2/njtest@tonjtest-6
Apr 26 18:29:30 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:33 DEBUG[16473]: chan_zap.c:4035 __zt_exception: Exception on 13, channel 1
Apr 26 18:29:33 DEBUG[16473]: chan_zap.c:3269 zt_handle_event: Got event On hook(1) on channel 1 (index 0)
Apr 26 18:29:33 DEBUG[16473]: chan_zap.c:1372 zt_disable_ec: disabled echo cancellation on channel 1
Apr 26 18:29:33 DEBUG[16473]: channel.c:2847 ast_generic_bridge: Didn't get a frame from channel: Zap/1-1
Apr 26 18:29:33 DEBUG[16473]: channel.c:3100 ast_channel_bridge: Bridge stops bridging channels IAX2/njtest@tonjtest-6 and Zap/1-1
Apr 26 18:29:33 DEBUG[16473]: chan_zap.c:2139 zt_hangup: Hangup: channel: 1 index = 0, normal = 13, callwait = -1, thirdcall = -1
Apr 26 18:29:33 DEBUG[16473]: chan_zap.c:1372 zt_disable_ec: disabled echo cancellation on channel 1
Apr 26 18:29:33 DEBUG[16473]: chan_zap.c:2548 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/1-1
Apr 26 18:29:33 DEBUG[16473]: chan_zap.c:1309 update_conf: Updated conferencing on 1, with 0 conference users
   -- Hungup 'Zap/1-1'
Apr 26 18:29:33 DEBUG[16473]: res_monitor.c:257 ast_monitor_stop: monitor executing ( nice -n 19 soxmix "/var/spool/asterisk/monitor/20050426-182930-s-in.WAV" "/var/spool/asterisk/monitor/20050426-182930-s-out.WAV" "/var/spool/asterisk/monitor/20050426-182930-s.WAV"  && rm -f "/var/spool/asterisk/monitor/20050426-182930-s-"* ) &
Apr 26 18:29:33 DEBUG[16473]: app_dial.c:1350 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
Apr 26 18:29:33 DEBUG[16473]: pbx.c:1527 pbx_substitute_variables_helper_full: Expression is '0'
   -- Executing GotoIf("IAX2/njtest@tonjtest-6", "0 ?hangup") in new stack
Apr 26 18:29:33 DEBUG[16473]: pbx.c:5897 pbx_builtin_gotoif: Not taking any branch
   -- Executing NoOp("IAX2/njtest@tonjtest-6", "0") in new stack
   -- Executing VoiceMail("IAX2/njtest@tonjtest-6", "u1000") in new stack
Apr 26 18:29:33 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing '/var/spool/asterisk/voicemail/default/1000/unavail' (language 'en')
   -- Starting simple switch on 'Zap/1-1'
Apr 26 18:29:37 DEBUG[16473]: chan_iax2.c:6742 socket_read: Immediately destroying 6, having received hangup
Apr 26 18:29:37 DEBUG[16473]: app_voicemail.c:2067 leave_voicemail: Hang up during prefile playback
 == Spawn extension (incoming, s, 31) exited non-zero on 'IAX2/njtest@tonjtest-6'
   -- Executing System("IAX2/njtest@tonjtest-6", "/bin/rm /tmp/20050426-182856-6001.gsm") in new stack
Apr 26 18:29:37 DEBUG[16473]: channel.c:1243 ast_settimeout: Scheduling timer at 0 sample intervals
Apr 26 18:29:37 DEBUG[16473]: chan_iax2.c:2971 iax2_hangup: We're hanging up IAX2/njtest@tonjtest-6 now...
Apr 26 18:29:37 DEBUG[16473]: chan_iax2.c:2981 iax2_hangup: Really destroying IAX2/njtest@tonjtest-6 now...
   -- Hungup 'IAX2/njtest@tonjtest-6'
Apr 26 18:29:37 DEBUG[16473]: chan_zap.c:4035 __zt_exception: Exception on 13, channel 1
Apr 26 18:29:37 DEBUG[16473]: chan_zap.c:3269 zt_handle_event: Got event On hook(1) on channel 1 (index 0)
Apr 26 18:29:37 DEBUG[16473]: chan_zap.c:1372 zt_disable_ec: disabled echo cancellation on channel 1
Apr 26 18:29:37 DEBUG[16473]: chan_zap.c:5158 ss_thread: waitfordigit returned < 0...
Apr 26 18:29:37 DEBUG[16473]: chan_zap.c:2139 zt_hangup: Hangup: channel: 1 index = 0, normal = 13, callwait = -1, thirdcall = -1
Apr 26 18:29:37 DEBUG[16473]: chan_zap.c:1372 zt_disable_ec: disabled echo cancellation on channel 1
Apr 26 18:29:37 DEBUG[16473]: chan_zap.c:2548 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/1-1
Apr 26 18:29:37 DEBUG[16473]: chan_zap.c:1309 update_conf: Updated conferencing on 1, with 0 conference users
   -- Hungup 'Zap/1-1'
Comments:By: Kevin P. Fleming (kpfleming) 2005-04-26 23:39:19

Something doesn't make sense here... this snip of your debug output:

   -- Executing GotoIf("Zap/1-1", "1 ?callaccepted") in new stack
   -- Goto (macro-screen,s,18)
   -- Executing NoOp("Zap/1-1", "0") in new stack

Shows the GotoIf() going to "callaccepted" as step 18, but in your dialplan snippet it is step 17. Step 18 is the NoOp, and if step 17 gets skipped then the variable will not be set to 1.

Are you _absolutely_ sure that this debug output came from this exact dialplan? If so, then the problem is not with SetGlobalVar (which really cannot fail), but with GotoIf.
By: Chris Hozian (chozian) 2005-04-27 08:17:04

Yes, I have reverified this problem.  The debug output I sent you matches that of my retest.

It does appear to be a problem with GotoIf when called from a macro by the Dial application.  It seems to be going to the priority+1 of that which it is supposed to go to.
By: Kevin P. Fleming (kpfleming) 2005-04-29 10:22:09

Fix has been committed to CVS, thanks for the report!