Summary: | ASTERISK-19205: Most Unique pattern matching broken when trailing "-" is part of extension | ||||||
Reporter: | Philippe Lindheimer (p_lindheimer) | Labels: | |||||
Date Opened: | 2012-01-17 00:19:01.000-0600 | Date Closed: | 2012-11-27 17:50:45.000-0600 | ||||
Priority: | Minor | Regression? | No | ||||
Status: | Closed/Complete | Components: | Core/PBX | ||||
Versions: | 1.8.7.2 | Frequency of Occurrence | Constant | ||||
Related Issues: |
| ||||||
Environment: | Attachments: | ||||||
Description: | The following FreePBX bug has some information. The crux is as follows. FreePBX uses some dialplan where extension patterns take on a format that might look like: "_RG-10111-." for a pattern. The crux of the issue is given two similar patterns, one always expect Asterisk to do the "most specific match". It appears starting with 1.6.2 something in Asterisk changed the behavior if that trailing "-" is left off. Tests were done on 1.4.32 where Asterisk seemed to work properly, and on 1.6.2.21 and 1.8.7.2 where it works improperly.
The following is a simple dialplan context that can be used to demonstrate the error: {noformat} [from-internal] exten => 1112,1,Goto(tst-parse,s,1) [tst-parse] exten => s,1,Noop(Running Parse Priority Text) exten => s,n,Dial(Local/RG-10111-99999@tst-parse) exten => s,n,Dial(Local/RG-20111-99999@tst-parse) exten => s,n,Hangup exten => h,1,Hangup exten => _RG-10111-.,1,Noop(IN 10111, this is CORRECT) exten => _RG-101-.,1,Noop(IN 101, this is WRONG) exten => _RG-20111.,1,Noop(IN 20111, this is CORRECT) exten => _RG-201.,1,Noop(IN 201, this is WRONG) {noformat} In this example, you dial "1112" to trigger teh context. Note the difference in the two sets of target dialplan, in one case there is a trailing "\-" and in the other case there is not. One wold expect both cases to execute the instruction that results in the "CORRECT" more specific match however leaving off the trailing "\-" is required for this to happen and if not, the wrong dialplan is executed. The results from 1.4 show proper execution: {noformat} -- Executing [1112@from-internal:1] Goto("SIP/7001-000005bf", "tst-parse|s|1") in new stack -- Goto (tst-parse,s,1) -- Executing [s@tst-parse:1] NoOp("SIP/7001-000005bf", "Running Parse Priority Text") in new stack -- Executing [s@tst-parse:2] Dial("SIP/7001-000005bf", "Local/RG-10111-99999@tst-parse") in new stack -- Called RG-10111-99999@tst-parse -- Executing [RG-10111-99999@tst-parse:1] NoOp("Local/RG-10111-99999@tst-parse-8d8c,2", "IN 10111| this is CORRECT") in new stack == Auto fallthrough, channel 'Local/RG-10111-99999@tst-parse-8d8c,2' status is 'UNKNOWN' -- Executing [h@tst-parse:1] Hangup("Local/RG-10111-99999@tst-parse-8d8c,2", "") in new stack == Spawn extension (tst-parse, h, 1) exited non-zero on 'Local/RG-10111-99999@tst-parse-8d8c,2' == Everyone is busy/congested at this time (1:0/0/1) -- Executing [s@tst-parse:3] Dial("SIP/7001-000005bf", "Local/RG-20111-99999@tst-parse") in new stack -- Called RG-20111-99999@tst-parse -- Executing [RG-20111-99999@tst-parse:1] NoOp("Local/RG-20111-99999@tst-parse-6a9b,2", "IN 20111| this is CORRECT") in new stack == Auto fallthrough, channel 'Local/RG-20111-99999@tst-parse-6a9b,2' status is 'UNKNOWN' -- Executing [h@tst-parse:1] Hangup("Local/RG-20111-99999@tst-parse-6a9b,2", "") in new stack == Spawn extension (tst-parse, h, 1) exited non-zero on 'Local/RG-20111-99999@tst-parse-6a9b,2' == Everyone is busy/congested at this time (1:0/0/1) -- Executing [s@tst-parse:4] Hangup("SIP/7001-000005bf", "") in new stack == Spawn extension (tst-parse, s, 4) exited non-zero on 'SIP/7001-000005bf' -- Executing [h@tst-parse:1] Hangup("SIP/7001-000005bf", "") in new stack == Spawn extension (tst-parse, h, 1) exited non-zero on 'SIP/7001-000005bf' {noformat} The results from 1.8 show improper execution, the same was seen on 1.6.2: {noformat} -- Executing [1112@from-internal:1] Goto("SIP/700-000003ac", "tst-parse,s,1") in new stack -- Goto (tst-parse,s,1) -- Executing [s@tst-parse:1] NoOp("SIP/700-000003ac", "Running Parse Priority Text") in new stack -- Executing [s@tst-parse:2] Dial("SIP/700-000003ac", "Local/RG-10111-99999@tst-parse") in new stack -- Called Local/RG-10111-99999@tst-parse -- Executing [RG-10111-99999@tst-parse:1] NoOp("Local/RG-10111-99999@tst-parse-6114;2", "IN 101, this is WRONG") in new stack -- Auto fallthrough, channel 'Local/RG-10111-99999@tst-parse-6114;2' status is 'UNKNOWN' -- Executing [h@tst-parse:1] Hangup("Local/RG-10111-99999@tst-parse-6114;2", "") in new stack == Spawn extension (tst-parse, h, 1) exited non-zero on 'Local/RG-10111-99999@tst-parse-6114;2' -- No one is available to answer at this time (1:0/0/0) -- Executing [s@tst-parse:3] Dial("SIP/700-000003ac", "Local/RG-20111-99999@tst-parse") in new stack -- Called Local/RG-20111-99999@tst-parse -- Executing [RG-20111-99999@tst-parse:1] NoOp("Local/RG-20111-99999@tst-parse-19bc;2", "IN 20111, this is CORRECT") in new stack -- Auto fallthrough, channel 'Local/RG-20111-99999@tst-parse-19bc;2' status is 'UNKNOWN' -- Executing [h@tst-parse:1] Hangup("Local/RG-20111-99999@tst-parse-19bc;2", "") in new stack {noformat} In the case of FreePBX, this breaks functionality when in the event that someone were to have two phone extensions configured with 101 and 10111. The following ticket with FreePBX references this issue: http://www.freepbx.org/trac/ticket/5521 | ||||||
Comments: | By: Richard Mudgett (rmudgett) 2012-01-17 10:46:00.811-0600 The fix for ASTERISK-18909 may have also fixed this issue. By: Matt Jordan (mjordan) 2012-09-25 16:58:42.184-0500 This was likely fixed by r347811. Can you confirm if this is still a problem? By: Matt Jordan (mjordan) 2012-10-17 09:10:57.710-0500 Suspended due to lack of activity. Please request a bug marshal in #asterisk-bugs on the IRC network irc.freenode.net to reopen the issue should you have the additional information requested. Further information can be found at http://www.asterisk.org/developers/bug-guidelines By: Birger "WIMPy" Harzenetter (wimpy) 2012-11-05 22:01:04.430-0600 I just hit a similar issue on the current TRUNK version. Here are 6 test calls. The first half with a pattern of _foo-! and the second half with _foo. Both trying to Goto foo-1, foo-2 and foo- in that order. {noformat} exten => start,1,Answer() exten => start,n,Read(x,,1) exten => start,n,Verbose(0,Goto(foo-${x},1)) exten => start,n,Goto(foo-${x},1) exten => foo-1,1,Verbose(0,hit foo-1) exten => _foo-!,1,Verbose(0,hit _foo-! / ${EXTEN}) {noformat} {noformat} [2012-11-06 04:43:36] -- Executing [start@ssmmc:1] Answer("lcr/121", "") in new stack [2012-11-06 04:43:36] -- Executing [start@ssmmc:2] Read("lcr/121", "x,,1") in new stack [2012-11-06 04:43:36] -- Accepting a maximum of 1 digits. [2012-11-06 04:43:41] -- User entered '1' [2012-11-06 04:43:41] -- Executing [start@ssmmc:3] Verbose("lcr/121", "0,Goto(foo-1,1)") in new stack [2012-11-06 04:43:41] Goto(foo-1,1) [2012-11-06 04:43:41] -- Executing [start@ssmmc:4] Goto("lcr/121", "foo-1,1") in new stack [2012-11-06 04:43:41] -- Goto (ssmmc,foo-1,1) [2012-11-06 04:43:41] -- Executing [foo-1@ssmmc:1] Verbose("lcr/121", "0,hit foo-1") in new stack [2012-11-06 04:43:41] hit foo-1 {noformat} {noformat} [2012-11-06 04:43:48] -- Executing [start@ssmmc:1] Answer("lcr/122", "") in new stack [2012-11-06 04:43:48] -- Executing [start@ssmmc:2] Read("lcr/122", "x,,1") in new stack [2012-11-06 04:43:48] -- Accepting a maximum of 1 digits. [2012-11-06 04:43:49] -- User entered '2' [2012-11-06 04:43:49] -- Executing [start@ssmmc:3] Verbose("lcr/122", "0,Goto(foo-2,1)") in new stack [2012-11-06 04:43:49] Goto(foo-2,1) [2012-11-06 04:43:49] -- Executing [start@ssmmc:4] Goto("lcr/122", "foo-2,1") in new stack [2012-11-06 04:43:49] -- Goto (ssmmc,foo-2,1) [2012-11-06 04:43:49] -- Executing [foo-2@ssmmc:1] Verbose("lcr/122", "0,hit _foo-! / foo-2") in new stack [2012-11-06 04:43:49] hit _foo-! / foo-2 {noformat} {noformat} [2012-11-06 04:43:54] -- Executing [start@ssmmc:1] Answer("lcr/123", "") in new stack [2012-11-06 04:43:54] -- Executing [start@ssmmc:2] Read("lcr/123", "x,,1") in new stack [2012-11-06 04:43:54] -- Accepting a maximum of 1 digits. [2012-11-06 04:43:55] -- User entered nothing. [2012-11-06 04:43:55] -- Executing [start@ssmmc:3] Verbose("lcr/123", "0,Goto(foo-,1)") in new stack [2012-11-06 04:43:55] Goto(foo-,1) [2012-11-06 04:43:55] -- Executing [start@ssmmc:4] Goto("lcr/123", "foo-,1") in new stack [2012-11-06 04:43:55] -- Goto (ssmmc,foo-,1) [2012-11-06 04:43:55] WARNING[626][C-00000089]: pbx.c:6161 __ast_pbx_run: Channel 'lcr/123' sent to invalid extension but no invalid handler: context,exten,priority=ssmmc,foo-,1 {noformat} {noformat} exten => start,1,Answer() exten => start,n,Read(x,,1) exten => start,n,Verbose(0,Goto(foo-${x},1)) exten => start,n,Goto(foo-${x},1) exten => foo-1,1,Verbose(0,hit foo-1) exten => _foo.,1,Verbose(0,hit _foo. / ${EXTEN}) {noformat} {noformat} [2012-11-06 04:46:08] -- Executing [start@ssmmc:1] Answer("lcr/124", "") in new stack [2012-11-06 04:46:08] -- Executing [start@ssmmc:2] Read("lcr/124", "x,,1") in new stack [2012-11-06 04:46:08] -- Accepting a maximum of 1 digits. [2012-11-06 04:46:09] -- User entered '1' [2012-11-06 04:46:09] -- Executing [start@ssmmc:3] Verbose("lcr/124", "0,Goto(foo-1,1)") in new stack [2012-11-06 04:46:09] Goto(foo-1,1) [2012-11-06 04:46:09] -- Executing [start@ssmmc:4] Goto("lcr/124", "foo-1,1") in new stack [2012-11-06 04:46:09] -- Goto (ssmmc,foo-1,1) [2012-11-06 04:46:09] -- Executing [foo-1@ssmmc:1] Verbose("lcr/124", "0,hit foo-1") in new stack [2012-11-06 04:46:09] hit foo-1 {noformat} {noformat} [2012-11-06 04:46:11] -- Executing [start@ssmmc:1] Answer("lcr/125", "") in new stack [2012-11-06 04:46:11] -- Executing [start@ssmmc:2] Read("lcr/125", "x,,1") in new stack [2012-11-06 04:46:11] -- Accepting a maximum of 1 digits. [2012-11-06 04:46:13] -- User entered '2' [2012-11-06 04:46:13] -- Executing [start@ssmmc:3] Verbose("lcr/125", "0,Goto(foo-2,1)") in new stack [2012-11-06 04:46:13] Goto(foo-2,1) [2012-11-06 04:46:13] -- Executing [start@ssmmc:4] Goto("lcr/125", "foo-2,1") in new stack [2012-11-06 04:46:13] -- Goto (ssmmc,foo-2,1) [2012-11-06 04:46:13] -- Executing [foo-2@ssmmc:1] Verbose("lcr/125", "0,hit _foo. / foo-2") in new stack [2012-11-06 04:46:13] hit _foo. / foo-2 {noformat} {noformat} [2012-11-06 04:46:15] -- Executing [start@ssmmc:1] Answer("lcr/126", "") in new stack [2012-11-06 04:46:15] -- Executing [start@ssmmc:2] Read("lcr/126", "x,,1") in new stack [2012-11-06 04:46:15] -- Accepting a maximum of 1 digits. [2012-11-06 04:46:16] -- User entered nothing. [2012-11-06 04:46:16] -- Executing [start@ssmmc:3] Verbose("lcr/126", "0,Goto(foo-,1)") in new stack [2012-11-06 04:46:16] Goto(foo-,1) [2012-11-06 04:46:16] -- Executing [start@ssmmc:4] Goto("lcr/126", "foo-,1") in new stack [2012-11-06 04:46:16] -- Goto (ssmmc,foo-,1) [2012-11-06 04:46:16] WARNING[1976][C-0000008c]: pbx.c:6161 __ast_pbx_run: Channel 'lcr/126' sent to invalid extension but no invalid handler: context,exten,priority=ssmmc,foo-,1 {noformat} In the last example the trailing - is only in the Goto, not in the extension pattern so there seems to be something more to it. By: Richard Mudgett (rmudgett) 2012-11-19 16:41:58.577-0600 Birger The last test is invalid because the '-' characters are treated as nonexistent. goto(foo-,1) is the same as goto(foo,1) which cannot match "_foo.". By: Richard Mudgett (rmudgett) 2012-11-19 16:42:52.565-0600 See reviewboard: https://reviewboard.asterisk.org/r/2201/ By: Birger "WIMPy" Harzenetter (wimpy) 2012-11-20 17:17:31.136-0600 I found the same information about "-" being ignored in ASTERISK-16121 but I cannot find any documentation on that special behavior, neither in the wiki ( https://wiki.asterisk.org/wiki/display/AST/Contexts%2C+Extensions%2C+and+Priorities https://wiki.asterisk.org/wiki/display/AST/Pattern+Matching ) nor in the sample config. That comes as a little surprise as this "feature" may have unexpected side-effects. BUT: Even if that's the expected behavior, it doesn't change the expected outcome of the 6 tests I did. The last one should still match. By: Richard Mudgett (rmudgett) 2012-11-20 18:26:06.042-0600 {quote} goto(foo-,1) is the same as goto(foo,1) which cannot match "_foo.". {quote} The last one cannot match since '.' matches *one* or more digits and that trailing '-' does not count. By: Richard Mudgett (rmudgett) 2012-11-20 19:04:24.771-0600 Asterisk has been skipping '\-' chars in patterns and the extens to match with patterns since at least Asterisk v1.2. It just has not been very consistent about ignoring the '\-' characters as shown by this issue. By: Birger "WIMPy" Harzenetter (wimpy) 2012-11-20 23:09:40.514-0600 Oh, yes. Now I see the issue. I was just thinking about unintended matches not the other way round. I really don't want to know how may hours I spent fiddling around in the dialplan in the past years because it didn't work as expected (by me) because of surprise features like this or the wildcards also working lower case. |