[asterisk-bugs] [JIRA] (ASTERISK-29998) sla: deadlock when calling SLAStation application

[N A (JIRA)]

     [ https://issues.asterisk.org/jira/browse/ASTERISK-29998?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

N A updated ASTERISK-29998:
---------------------------

    Attachment: exvvljatlc.txt

Actually, deadlock was conservative - I tried this on another system and this causes a crash there:

[2022-04-01 23:27:19]     -- Local/disa at bla-out-00000004;1 answered
[2022-04-01 23:27:19] DEBUG[29440]: channel.c:3065 ast_waitfor_nandfds: Thread LWP 29440 is blocking 'Local/4002702596 at astrex-lines-pre-00000003;2', already blocked by thread LWP 29503 in procedure ast_waitfor_nandfds
[2022-04-01 23:27:19] ERROR[29440]: channel.c:3065 ast_waitfor_nandfds: FRACK!, Failed assertion 0 (0)
[2022-04-01 23:27:20] ERROR[29440]:   Got 8 backtrace records
# 0: asterisk __ast_assert_failed()
# 1: asterisk <unknown>()
# 2: asterisk ast_waitfor_nandfds()
# 3: asterisk ast_waitfor_n()
# 4: asterisk <unknown>()
# 5: asterisk <unknown>()
# 6: [0x7f45b9e13fa3] libpthread.so.0 pthread_create.c:487 start_thread()
# 7: [0x7f45b98a7eff] libc.so.6 clone.S:97 clone()

core-full.txt is attached.



> sla: deadlock when calling SLAStation application
> -------------------------------------------------
>
>                 Key: ASTERISK-29998
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-29998
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Applications/app_meetme
>    Affects Versions: 18.6.0
>            Reporter: N A
>         Attachments: exvvljatlc.txt
>
>
> As soon as I call the SLAStation application in the dialplan, deadlock ensues almost instantly:
> Initially, I get this:
> [Mar 30 20:10:16] DEBUG[9760]: channel.c:3073 ast_waitfor_nandfds: Thread LWP 9760 is blocking 'DAHDI/5-1', already blocked by thread LWP 9655 in procedure ast_waitfor_nandfds
> An IAX2 trunk call that normally works fails, seemingly as a result of that. I can get a Local channel to at least dial.
> Then, the longer one waits, the worse the issue progressively becomes,and it's very clear that there is a deadlock here, between 9862 and 9863:
> {noformat}
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9863]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9863 is blocking 'DAHDI/5-1', already blocked by thread LWP 9862 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:04] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9863]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9863 is blocking 'DAHDI/5-1', already blocked by thread LWP 9862 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9863]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9863 is blocking 'DAHDI/5-1', already blocked by thread LWP 9862 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9863]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9863 is blocking 'DAHDI/5-1', already blocked by thread LWP 9862 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9863]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9863 is blocking 'DAHDI/5-1', already blocked by thread LWP 9862 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> [Mar 30 20:20:05] DEBUG[9862][C-00000001]: chan_dahdi.c:8742 dahdi_read: Thread LWP 9862 is blocking 'DAHDI/5-1', already blocked by thread LWP 9863 in procedure ast_waitfor_nandfds
> {noformat}
> Interestingly, "core show locks" does not return anything (no locks held).
> Finally, to round things off, when I hang up the phone that called SLAStation, I get thousands of these per second in the log:
> {noformat}
> [Mar 30 20:10:21] DEBUG[9760]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for DAHDI - 5
> [Mar 30 20:10:21] DEBUG[9760]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for DAHDI - 5
> [Mar 30 20:10:21] DEBUG[9760]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for DAHDI - 5
> [Mar 30 20:10:21] DEBUG[9760]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for DAHDI - 5
> [Mar 30 20:10:21] WARNING[9760]: logger: ***: Log queue threshold (1000) exceeded.  Discarding new messages.
> [Mar 30 20:10:21] WARNING[9559]: logger: ***: Logging resumed.  354 messages discarded.
> {noformat}
> This was initially. When I recompiled with developer options for locks and memory, this doesn't seem to happen anymore. However, the thread blocking still occurs.
> minimal sla.conf:
> {noformat}
> [general]
> attemptcallerid = no
> [line1]
> type = trunk
> ringtimeout = 99999
> device = Local/s at line1out
> barge = yes
> hold = open
> [station1]
> type = station
> trunk = line1
> device = DAHDI/5
> {noformat}



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