| Summary: | ASTERISK-30221: Channel masquerades screw up groups | ||
| Reporter: | N A (InterLinked) | Labels: | |
| Date Opened: | 2022-09-11 14:24:13 | Date Closed: | 2022-09-12 08:58:10 |
| Priority: | Major | Regression? | |
| Status: | Closed/Complete | Components: | Core/Bridging Functions/func_groupcount |
| Versions: | 18.14.0 | Frequency of Occurrence | Constant |
| Related Issues: | |||
| Environment: | Attachments: | ||
| Description: | RELATED to: ASTERISK-30210
So circling back to the weird thing with masquerades: I don't think it has anything to do with optimizations, per se, I think it's the masquerade itself. For some reason, it seems to consistently screw up groups. Here is an example of a system caught red handed where, after a masquerade occurs, suddenly all of the groups on all channels on the system suddenly become assigned to a *SINGLE* channel. This includes the bizarre scenario of also having the same group assignment twice on the same channel, such that GROUP_COUNT returns 2 even those there is only one channel in the group. This has the effect afterwards of putting the channel into an infinite loop due to dialplan logic that expects 2 channels. None of this happened prior to upgrading from 18.9.0 to 18.14.0, so a regression is possible but I'm not yet positive either. It also seems weird that masquerades would be broken in such a a fundamental way. The group screwing up seems to vary: the example in ASTERISK-30210 simply made all the groups disappear, in this case they all hop onto a single channel even from other channels that still exist (as well as groups that no longer do so). Note also that this system includes the group variables patch on Gerrit and testing without that is difficult/impossible. The bug could very well be there too, though that doesn't explain why it's only triggered by masquerades. UPDATE - POC test with base 18.14.0 shows no issue, so likely related to func_groupcount.c changes Example: {noformat} voip*CLI> group show channels Channel Group Category PJSIP/ATAxGrandstream1-00000040 PJSIP/ATAxGrandstream1 deviceinuse PJSIP/ATAxGrandstream1-00000040 1 lineinuse PJSIP/ATAxGrandstream1-00000040 1 oe PJSIP/ATAxGrandstream1-00000040 1 oeall Local/1*4002702122*92310041@outgoing-00000117;2 1 oeall Local/1*4002702122*92310041@outgoing-00000117;2 1 lineinuseoutboundunanswered Local/1*4002702122*92310041@outgoing-00000117;2 1 bridgedcalls Local/2310041@route-0000011a;2 looparound_231004tone side Local/2310041@route-0000011a;2 looparound_231004 looparound 9 active channels ... [2022-09-11 19:13:13] -- Executing [s@loop:10] Bridge("Local/2310042@route-0000011e;2", "Local/2310041@route-0000011a;2") in new stack [2022-09-11 19:13:13] -- Local/2310042@route-0000011e;1 answered Local/92310042@originate-local-0000011c;2 [2022-09-11 19:13:13] -- Local/92310042@originate-local-0000011c;1 answered Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:13] -- Local/92310042@originate-local-0000011c;1 Internal Gosub(outgoing-ring-answer,s,1) start [2022-09-11 19:13:13] -- Executing [s@outgoing-ring-answer:1] ASTREXOutgoingAnswer("Local/92310042@originate-local-0000011c;1", "") in new stack [2022-09-11 19:13:14] -- Channel Local/2310042@route-0000011e;1 joined 'simple_bridge' basic-bridge <494a5de1-aac8-46f6-a561-f199d443704a> [2022-09-11 19:13:14] -- Executing [s@outgoing-ring-answer:2] Return("Local/92310042@originate-local-0000011c;1", "") in new stack [2022-09-11 19:13:14] -- Channel Local/92310042@originate-local-0000011c;2 joined 'simple_bridge' basic-bridge <494a5de1-aac8-46f6-a561-f199d443704a> [2022-09-11 19:13:14] == Spawn extension (originate-local, , 1) exited non-zero on 'Local/92310042@originate-local-0000011c;1' [2022-09-11 19:13:14] -- Local/92310042@originate-local-0000011c;1 Internal Gosub(outgoing-ring-answer,s,1) complete GOSUB_RETVAL= [2022-09-11 19:13:14] == Spawn extension (loop, s, 6) exited non-zero on 'Surrogate/Local/2310041@route-0000011a;2' ... [2022-09-11 19:13:14] -- Channel Local/92310041@originate-local-00000118;2 joined 'simple_bridge' basic-bridge <34bf92cb-33be-41d1-b822-c56b79c5ff2d> [2022-09-11 19:13:14] --> Write on Channel Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/6*4002702128*92310042@outgoing-0000011b;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:14] -- Channel Local/92310041@originate-local-00000118;1 joined 'simple_bridge' basic-bridge <3ce0fb16-2e69-4539-891f-7bbfc10ecb8f> [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: -1 [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:14] -- Channel Local/1*4002702122*92310041@outgoing-00000117;1 joined 'simple_bridge' basic-bridge <3ce0fb16-2e69-4539-891f-7bbfc10ecb8f> [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: -1 [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/1*4002702122*92310041@outgoing-00000117;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/1*4002702122*92310041@outgoing-00000117;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/1*4002702122*92310041@outgoing-00000117;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: -1 [2022-09-11 19:13:14] <--Read on Channel Local/6*4002702128*92310042@outgoing-0000011b;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/6*4002702128*92310042@outgoing-0000011b;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: CONNECTED LINE [2022-09-11 19:13:14] Bytes: 88 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/1*4002702122*92310041@outgoing-00000117;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/1*4002702122*92310041@outgoing-00000117;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/1*4002702122*92310041@outgoing-00000117;1 [2022-09-11 19:13:14] <--Read on Channel Local/6*4002702128*92310042@outgoing-0000011b;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: CONNECTED LINE [2022-09-11 19:13:14] Bytes: 88 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] SubClass: -1 [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/1*4002702122*92310041@outgoing-00000117;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/6*4002702128*92310042@outgoing-0000011b;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/6*4002702128*92310042@outgoing-0000011b;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/1*4002702122*92310041@outgoing-00000117;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: CONNECTED LINE [2022-09-11 19:13:14] Bytes: 88 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/6*4002702128*92310042@outgoing-0000011b;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/1*4002702122*92310041@outgoing-00000117;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/1*4002702122*92310041@outgoing-00000117;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: CONNECTED LINE [2022-09-11 19:13:14] Bytes: 88 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/1*4002702122*92310041@outgoing-00000117;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] --> Write on Channel Local/1*4002702122*92310041@outgoing-00000117;1 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] <--Read on Channel Local/1*4002702122*92310041@outgoing-00000117;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] [2022-09-11 19:13:14] <--Read on Channel Local/1*4002702122*92310041@outgoing-00000117;2 [2022-09-11 19:13:14] FrameType: CONTROL [2022-09-11 19:13:14] SubClass: SRCCHANGE [2022-09-11 19:13:14] Bytes: 0 [2022-09-11 19:13:14] Src: NOT PRESENT [2022-09-11 19:13:14] voip*CLI> group show channels Channel Group Category Local/2310041@route-0000011a;2 PJSIP/ATAxGrandstream1 deviceinuse Local/2310041@route-0000011a;2 1 lineinuse Local/2310041@route-0000011a;2 1 oe Local/2310041@route-0000011a;2 1 oeall Local/2310041@route-0000011a;2 1 oeall Local/2310041@route-0000011a;2 1 lineinuseoutboundunanswered Local/2310041@route-0000011a;2 1 bridgedcalls Local/2310041@route-0000011a;2 looparound_231004tone side Local/2310041@route-0000011a;2 looparound_231004 looparound Local/2310041@route-0000011a;2 PJSIP/ATAxLB1 deviceinuse Local/2310041@route-0000011a;2 6 lineinuse Local/2310041@route-0000011a;2 6 oe Local/2310041@route-0000011a;2 6 oeall Local/2310041@route-0000011a;2 6 oeall Local/2310041@route-0000011a;2 6 bridgedcalls Local/2310041@route-0000011a;2 looparound_231004 side Local/2310041@route-0000011a;2 looparound_231004 looparound Local/2310041@route-0000011a;2 6 lineinuseoutboundanswered Local/1*4002702122*92310041@outgoing-00000117;2 1 lineinuseoutboundanswered 19 active channels {noformat} | ||
| Comments: | By: Asterisk Team (asteriskteam) 2022-09-11 14:24:18.942-0500 Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. Please note that log messages and other files should not be sent to the Sangoma Asterisk Team unless explicitly asked for. All files should be placed on this issue in a sanitized fashion as needed. A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process]. Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur. Please note that by submitting data, code, or documentation to Sangoma through JIRA, you accept the Terms of Use present at [https://www.asterisk.org/terms-of-use/|https://www.asterisk.org/terms-of-use/]. By: N A (InterLinked) 2022-09-11 14:50:55.790-0500 I'm pretty sure this is a bug with group vars, so closing for now as that's unmerged code, and will take up the issue separately there. If further testing reveals otherwise, will reopen this. By: Mark Murawski (kobaz) 2022-09-12 08:31:05.687-0500 I disagree with the closure here. Group variables are not yet merged and this bug report is unrelated to group variables. This bug report here is for groups themselves. By: Mark Murawski (kobaz) 2022-09-12 08:41:44.217-0500 Wait... are you saying you reported an issue against unmerged code? Regarding: UPDATE - POC test with base 18.14.0 shows no issue, so likely related to func_groupcount.c changes Have you tried against all LTS branches? By: N A (InterLinked) 2022-09-12 08:57:09.041-0500 I think it's related to group vars, because the bug only happens on a system with your latest patch. It does not happen on 18.14.0 base. (I also sent you some IRC messages with further debug on this) By: Asterisk Team (asteriskteam) 2022-09-12 08:57:10.291-0500 This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable. | ||