[asterisk-bugs] [JIRA] (ASTERISK-29428) DTMF on progress results in infinite loop if progress followed by hangup received

George Joseph (JIRA) noreply at issues.asterisk.org
Mon May 17 07:32:17 CDT 2021 

    [ https://issues.asterisk.org/jira/browse/ASTERISK-29428?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=254907#comment-254907 ] 

George Joseph commented on ASTERISK-29428:
------------------------------------------

| Hope that helps! Do you need any more info from me?

Nope.  I can reproduce the issue.



> DTMF on progress results in infinite loop if progress followed by hangup received
> ---------------------------------------------------------------------------------
>
>                 Key: ASTERISK-29428
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-29428
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Applications/app_dial
>    Affects Versions: 18.3.0
>         Environment: Debian 10
>            Reporter: N A
>            Assignee: Unassigned
>         Attachments: debug.txt
>
>
> I've been trying to troubleshoot a weird issue I can reproduce consistently, which results in thousands of these spamming the console:
> ```
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> ```
> The frame type in question is an AST_FRAME_DTMF_END frame. I tested a few different ways, and what's happening is I'm trying to call a remote FXO line that appears to be down currently (HANGUPCAUSE = 20). Calling it directly, I just hear a reorder tone (since that's how it gets handled that particular way). In a different place, I have the D option configured to send DTMF on Progress, and the CLI confirms that's what it's trying to do:
> ```
> [May 12 22:02:42]     -- Channel Local/SIPATAxLA1 at centrex-outgoing-00001d85;2 joined 'softmix' base-bridge <9f5d2e80-cdf9-433f-b84d-2494409ea318>
> [May 12 22:02:42]     -- Local/SIPATAxLA1 at centrex-outgoing-00001d85;1 requested media update control 20, passing it to Local/REDACTED at centrex-originate-local-00001d87;1
> [May 12 22:02:42]     -- Local/REDACTED at centrex-originate-local-00001d87;2 requested media update control 20, passing it to Local/FX1A1DC824 at centrex-fx-00001d88;1
> [May 12 22:02:42]     -- Local/FX1A1DC824 at centrex-fx-00001d88;2 requested media update control 20, passing it to IAX2/REDACTED:4569-13337
> [May 12 22:02:42]     -- Local/SIPATAxLA1 at centrex-outgoing-00001d85;1 requested media update control 20, passing it to Local/REDACTED at centrex-originate-local-00001d87;1
> [May 12 22:02:42]     -- Local/REDACTED at centrex-originate-local-00001d87;2 requested media update control 20, passing it to Local/FX1A1DC824 at centrex-fx-00001d88;1
> [May 12 22:02:42]     -- Local/FX1A1DC824 at centrex-fx-00001d88;2 requested media update control 20, passing it to IAX2/REDACTED:4569-13337
> [May 12 22:02:44]     -- IAX2/REDACTED:4569-13337 is making progress passing it to Local/FX1A1DC824 at centrex-fx-00001d88;2
> [May 12 22:02:44]     -- Local/FX1A1DC824 at centrex-fx-00001d88;1 is making progress passing it to Local/REDACTED at centrex-originate-local-00001d87;2
> [May 12 22:02:44]     -- Sending DTMF 'REDACTED' to the called party as result of receiving a PROGRESS message.
> [May 12 22:02:44]     -- Local/REDACTED at centrex-originate-local-00001d87;1 is making progress passing it to Local/SIPATAxLA1 at centrex-outgoing-00001d85;1
> [May 12 22:02:44]     -- Hungup 'IAX2/redacted:4569-13337'
> [May 12 22:02:44]   == Everyone is busy/congested at this time (1:0/0/1)
> [May 12 22:02:44]     -- Executing [s at REDACTED-simple:4] Return("Local/FX1A1DC824 at centrex-fx-00001d88;2", "20") in new stack
> [May 12 22:02:44]     -- Executing [FX1A1DC824 at centrex-fx:2] Hangup("Local/FX1A1DC824 at centrex-fx-00001d88;2", "20") in new stack
> [May 12 22:02:44]   == Spawn extension (centrex-fx, FX1A1DC824, 2) exited non-zero on 'Local/FX1A1DC824 at centrex-fx-00001d88;2'
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> [2021-05-12 22:02:44] WARNING[1817][C-00001ec9]: app_dial.c:1798 wait_for_answer: Unable to forward frametype: 2
> ```
> That goes on forever, hundreds of times per second, until I manually hang up the call. All the while, I don't hear anything in the call itself and dialplan execution doesn't continue until I hang up. There seems to be some kind of bug here with not accounting for something here but I can't quite put my finger on it... however, this does happen every single time. It's not able to send the DTMF, but this basically locks up the call afterwards for perpetuity because of that.
> It's worth mentioning the end call that is being made (via IAX2), is to another Asterisk machine over the Internet. That is to say, not my dialplan. The FXO gateway is connected to that Asterisk switch. It's possible that switch is introducing a Progress() it shouldn't be that's causing this to happen, but it seems Asterisk should be able to handle that.



--
This message was sent by Atlassian JIRA
(v6.2#6252)

More information about the asterisk-bugs mailing list