[Home]

Summary:ASTERISK-13256: [patch] Macro execution doesn't get to "h" extension
Reporter:wetwired (wetwired)Labels:
Date Opened:2008-12-22 06:13:36.000-0600Date Closed:2009-02-24 12:07:54.000-0600
Priority:BlockerRegression?Yes
Status:Closed/CompleteComponents:Applications/app_macro
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 20090210__bug14122.diff.txt
Description:In asterisk-1.4.23-rc3 (and in SVN 1.4 branch) execution of macro context interrupted by hangup never gets to "h" context defined by "catch h =>". Instead of this, execution returns to "h" extension of calling context. In asterisk-1.4.23-rc2 and earlier, execution was finishing in macro "catch h =>" branch.

****** ADDITIONAL INFORMATION ******

Dialplan:
context outgoing
{
   123 =>
   {
       &test();
   }

   h =>
   {
       NoOp(HANGUP);
   }
}

macro test()
{
   SayDigits(${MACRO_EXTEN});

   catch h
   {
       NoOp(CATCH HANGUP);
   }
}

When I hang up during playback of digits:

In asterisk-1.4.23-rc2:
   -- Executing [123@outgoing:1] Macro("SIP/111-09335600", "test") in new stack
   -- Executing [s@macro-test:1] SayDigits("SIP/111-09335600", "123") in new stack
   -- <SIP/111-09335600> Playing 'digits/1' (language 'en')
   -- <SIP/111-09335600> Playing 'digits/2' (language 'en')
 == Spawn extension (macro-test, s, 1) exited non-zero on 'SIP/111-09335600' in macro 'test'
 == Spawn extension (macro-test, s, 1) exited non-zero on 'SIP/111-09335600'
   -- Executing [h@macro-test:1] NoOp("SIP/111-09335600", "CATCH HANGUP") in new stack

asterisk-1.4.23-rc3:
   -- Executing [123@outgoing:1] Macro("SIP/111-09e78680", "test") in new stack
   -- Executing [s@macro-test:1] SayDigits("SIP/111-09e78680", "123") in new stack
   -- <SIP/111-09e78680> Playing 'digits/1' (language 'en')
   -- <SIP/111-09e78680> Playing 'digits/2' (language 'en')
 == Spawn extension (macro-test, s, 1) exited non-zero on 'SIP/111-09e78680' in macro 'test'
 == Spawn extension (outgoing, 123, 1) exited non-zero on 'SIP/111-09e78680'
   -- Executing [h@outgoing:1] NoOp("SIP/111-09e78680", "HANGUP") in new stack
Comments:By: Leif Madsen (lmadsen) 2009-01-06 08:24:48.000-0600

murf: can you take a look at this issue and determine why this might be happening?

By: Steve Murphy (murf) 2009-01-13 11:37:33.000-0600

wetwired-- please apply the attached patch and report on the results.


By: wetwired (wetwired) 2009-01-15 01:39:40.000-0600

Thanks, with this patch everything's ok.

By: Andrew Lindh (andrew) 2009-01-15 03:07:44.000-0600

For hours I was beating my head against the proverbial brick wall on this one... I could not figure out why my app (called in a macro) was no longer running the 'h' extension in the macro when it was done. The patch seems to solve the problem for me. I did not test other digit/extension checking (eg Background), or should they not work (related to ASTERISK-13159)?



By: Andrew Lindh (andrew) 2009-01-15 03:55:34.000-0600

After some more testing, my asterisk crashes with this patch enabled. I seem to have some macro problems in general. But here's some crash info:

Program terminated with signal 11, Segmentation fault.
#0  0x080dea85 in __ast_pbx_run (c=0x82a2088) at pbx.c:2545
2545            emc = ast_strdupa(pbx_builtin_getvar_helper(c, "EXIT_MACRO_CONTEXT"));
#0  0x080dea85 in __ast_pbx_run (c=0x82a2088) at pbx.c:2545
       __old = 0x0
       __len = 136998992
       __new = 0x82a6630 "pbx_thread", ' ' <repeats 11 times>, "started at [ 2652] pbx.c ast_pbx_start()"
       found = 1
       res = -1
       autoloopflag = 0
       error = 1
       emc = 0x82a6fe8 " \b(\b>"
       __PRETTY_FUNCTION__ = "__ast_pbx_run"
#1  0x080df062 in pbx_thread (data=0x82a2088) at pbx.c:2628
       c = (struct ast_channel *) 0x82a2088
#2  0x081234d3 in dummy_start (data=0x82a65b0) at utils.c:856
       _buffer = {__routine = 0x806bef1 <ast_unregister_thread>,
 __arg = 0xb630ebb0, __canceltype = 0, __prev = 0x0}
       ret = (void *) 0x0
       a = {start_routine = 0x80df04b <pbx_thread>, data = 0x82a2088,
 name = 0x82a6630 "pbx_thread", ' ' <repeats 11 times>, "started at [ 2652] pbx.c ast_pbx_start()"}
       lock_info = (struct thr_lock_info *) 0x82a6728
       mutex_attr = {__mutexkind = 1}
       __PRETTY_FUNCTION__ = "dummy_start"
#3  0xb7f1a240 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
No symbol table info available.
#4  0xb7e3549e in clone () from /lib/tls/i686/cmov/libc.so.6
No symbol table info available.



By: Leif Madsen (lmadsen) 2009-01-15 08:15:58.000-0600

andrew:

Are you using safe_asterisk? If so, it should core dump the file to /tmp/.

If not, then you need to make sure asterisk is started with the 'g' flag (i.e. asterisk -cvvvvg) which will then dump the file in whatever location you executed the asterisk binary.

Make sure you have DONT_OPTIMIZE enabled in the Compiler Flags section as well.

By: Andrew Lindh (andrew) 2009-01-15 08:54:50.000-0600

I have this failing on a test machine so I'm not using safe_asterisk, but I ran it manually as asterisk -fgdvvv. DONT_OPTIMIZE and other DEGBUGs are set.

By: Leif Madsen (lmadsen) 2009-01-15 08:56:48.000-0600

Test machines are great! :)

Then the core file should be something like core.<process_PID> in the location where you ran asterisk -fgdvvv.

That's always worked for me at least...

By: Andrew Lindh (andrew) 2009-01-15 09:30:42.000-0600

An interesting point on this crash. I'm not using a macro when it dies. I'm using an auto-dial out, but it never does much.

Here's the console output:

Asterisk Ready.
Asterisk Malloc Debugger Started (see /var/log/asterisk/mmlog))
   -- Attempting call on Local/98605551212@inside/n for s@txfax:1 (Retry 1)
   -- Executing [98605551212@inside:1] NoOp("Local/98605551212@inside-2450,2", "Start") in new stack
   -- Executing [98605551212@inside:2] Dial("Local/98605551212@inside-2450,2", "SIP/8605551212@as5300") in new stack
   -- Called 8605551212@as5300
   -- Got SIP response 486 "Busy here" back from X.X.X.X
   -- SIP/as5300-082a4200 is busy
 == Everyone is busy/congested at this time (1:1/0/0)
   -- Executing [98605551212@inside:3] Congestion("Local/98605551212@inside-2450,2", "") in new stack
[Jan 15 10:24:02] NOTICE[29140]: pbx_spool.c:356 attempt_thread: Call failed to go through, reason (8) Congestion (circuits busy)
 == Spawn extension (inside, 98605551212, 3) exited non-zero on 'Local/98605551212@inside-2450,2'
Segmentation fault (core dumped)

By: Tilghman Lesher (tilghman) 2009-01-20 17:39:33.000-0600

Fixed.

By: Andrew Lindh (andrew) 2009-01-20 19:17:14.000-0600

New patch still crashes for me...

#0  0xb7e7aeca in strcmp () from /lib/tls/i686/cmov/libc.so.6
#1  0x080d9d2d in pbx_find_extension (chan=0x82a1b88, bypass=0x0,
   q=0xb63b3fd8, context=0x0, exten=0x8169e00 "h", priority=1, label=0x0,
   callerid=0x82a2720 "8605551212", action=E_MATCH) at pbx.c:979
#2  0x080dc65d in pbx_extension_helper (c=0x82a1b88, con=0x0, context=0x0,
   exten=0x8169e00 "h", priority=1, label=0x0,
   callerid=0x82a2720 "8605551212", action=E_MATCH) at pbx.c:1820
#3  0x080ddb78 in ast_exists_extension (c=0x82a1b88, context=0x0,
   exten=0x8169e00 "h", priority=1, callerid=0x82a2720 "5551212")
   at pbx.c:2293
#4  0x080debd0 in __ast_pbx_run (c=0x82a1b88) at pbx.c:2549
ASTERISK-1  0x080df0ce in pbx_thread (data=0x82a1b88) at pbx.c:2630
ASTERISK-2  0x0812392b in dummy_start (data=0x82a2998) at utils.c:856
ASTERISK-3  0xb7fc0240 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
ASTERISK-4  0xb7edb49e in clone () from /lib/tls/i686/cmov/libc.so.6

By: Andrew Lindh (andrew) 2009-01-21 06:29:46.000-0600

The third version does not crash.... It also seems to mostly work. The 'h' extension in the macro is still not running in some cases (it runs 'h' from the main context). If I call Hangup in the macro it should go to 'h' in the macro (so I think anyway).



By: Tilghman Lesher (tilghman) 2009-01-21 19:08:14.000-0600

andrew:  have you checked to see if the deepest macro is still executing when the call is hungup?  The code will only execute the "h" extension in a macro which is still executing.  If it exited, and the next macro up doesn't contain an "h" extension, then it is expected that the "h" extension would run from the main context, since it could not find it in the context where it hungup.

By: Leif Madsen (lmadsen) 2009-02-03 08:38:06.000-0600

andrew: ping?

By: Andrew Lindh (andrew) 2009-02-04 06:58:56.000-0600

Sorry, got stuck on a paying project.... I'll run some tests on past versions shortly.



By: Andrew Lindh (andrew) 2009-02-09 21:12:55.000-0600

I checked 1.4.17 vs. branch (1.4.23).

I tested two main conditions. One is when the channel hangs up during the call (automatic jump to 'h'), and the second is when the pbx calls Hangup in the macro to disconnect (that jumps to 'h').

The older version consistantly runs 'h' IN THE MACRO for both conditions.

The newer version runs 'h' from the main context when Hangup is called in the macro (rather than running 'h' in the macro). If the channel is disconnected then it runs 'h' in the macro and not the main context.

Since the pbx ran 'h' in the macro before, this behavior should be restored to be consistant in the newer version.

By: Tilghman Lesher (tilghman) 2009-02-10 12:18:14.000-0600

New patch uploaded.  Thank you for the two test scenarios.  I have tested both and they seem to work with this patch.

By: Andrew Lindh (andrew) 2009-02-10 16:18:47.000-0600

Patch 20090210 works better for me. One more problem I see with this patch. ARG is no longer valid in the macro when 'h' runs from a hangup (channel or app).

By: Tilghman Lesher (tilghman) 2009-02-10 16:23:37.000-0600

That's very true, but it's a consequence of the Macro having exited.  I don't think there's any way to change that.

By: Andrew Lindh (andrew) 2009-02-10 17:25:41.000-0600

It worked before (1.4.17). The Macro does not exit, ARG is used in the 'h' extension in the macro.



By: Tilghman Lesher (tilghman) 2009-02-11 10:06:56.000-0600

Actually, the macro DID exit in prior versions.  The bug was that it left those variables on the stack, which it should not have.

By: Andrew Lindh (andrew) 2009-02-11 12:08:19.000-0600

I see the macro exit now, I did not notice it... I guess ARG working was a "feature".

Workaround: I just set another variable to the value of the ARG I needed to use later in 'h'.

Testing in branch 1.4 is ok for me (in extensions.conf).

By: Digium Subversion (svnbot) 2009-02-11 14:54:23.000-0600

Repository: asterisk
Revision: 174885

U   branches/1.4/apps/app_macro.c
U   branches/1.4/main/pbx.c

------------------------------------------------------------------------
r174885 | tilghman | 2009-02-11 14:54:19 -0600 (Wed, 11 Feb 2009) | 13 lines

Restore a behavior that was recently changed, when we fixed issue ASTERISK-13115 and
issue ASTERISK-12632 (related to issue ASTERISK-6019).  When a hangup occurs during a Macro
execution in earlier 1.4, the h extension would execute within the Macro
context, whereas it was always supposed to execute only within the main context
(where Macro was called).  So this fix checks for an "h" extension in the
deepest macro context where a hangup occurred; if it exists, that "h" extension
executes, otherwise the main context "h" is executed.
(closes issue ASTERISK-13256)
Reported by: wetwired
Patches:
      20090210__bug14122.diff.txt uploaded by Corydon76 (license 14)
Tested by: andrew

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=174885

By: Digium Subversion (svnbot) 2009-02-11 14:55:51.000-0600

Repository: asterisk
Revision: 174886

_U  trunk/

------------------------------------------------------------------------
r174886 | tilghman | 2009-02-11 14:55:47 -0600 (Wed, 11 Feb 2009) | 19 lines

Blocked revisions 174885 via svnmerge

........
 r174885 | tilghman | 2009-02-11 14:54:18 -0600 (Wed, 11 Feb 2009) | 13 lines
 
 Restore a behavior that was recently changed, when we fixed issue ASTERISK-13115 and
 issue ASTERISK-12632 (related to issue ASTERISK-6019).  When a hangup occurs during a Macro
 execution in earlier 1.4, the h extension would execute within the Macro
 context, whereas it was always supposed to execute only within the main context
 (where Macro was called).  So this fix checks for an "h" extension in the
 deepest macro context where a hangup occurred; if it exists, that "h" extension
 executes, otherwise the main context "h" is executed.
 (closes issue ASTERISK-13256)
  Reported by: wetwired
  Patches:
        20090210__bug14122.diff.txt uploaded by Corydon76 (license 14)
  Tested by: andrew
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=174886