[asterisk-bugs] [JIRA] (ASTERISK-30055) HIgh CPU load when TURN server unreachable

Wed May 11 02:04:40 CDT 2022

Vitezslav Novy created ASTERISK-30055:
-----------------------------------------

             Summary: HIgh CPU load when TURN server unreachable
                 Key: ASTERISK-30055
                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-30055
             Project: Asterisk
          Issue Type: Bug
      Security Level: None
          Components: Resources/res_rtp_asterisk
    Affects Versions: 18.10.1
         Environment: LInux, Debian 11 bullseye 
            Reporter: Vitezslav Novy
            Severity: Major

We experience high CPU load caused by asterisk when TURN server is unreachable and chan_sip and webrtc phone tries to make a call.

I have identified a thread causing the high CPU load

#0  futex_abstimed_wait_cancelable (private=0x0, abstime=0x7f414c7ad880, expected=0x0, futex_word=0x7f41502a99cc) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f414c7ad880, mutex=0x7f41502a3470, cond=0x7f41502a99a0) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=cond at entry=0x7f41502a99a0, mutex=mutex at entry=0x7f41502a3470, abstime=abstime at entry=0x7f414c7ad880) at pthread_cond_wait.c:667
#3  0x0000556f29295da9 in __ast_cond_timedwait (filename=filename at entry=0x7f417c0c4010 "res_rtp_asterisk.c", lineno=lineno at entry=0x696, func=func at entry=0x7f417c0c8930 <__PRETTY_FUNCTION__.41691> "ast_rtp_ice_turn_request", cond_name=cond_name at entry=0x7f417c0c4075 "&rtp->cond", mutex_name=mutex_name at entry=0x7f417c0c5ca8 "ao2_object_get_lockaddr(instance)", cond=cond at entry=0x7f41502a99a0, t=0x7f41502a3470, abstime=abstime at entry=0x7f414c7ad880) at lock.c:653
#4  0x00007f417c0b21de in ast_rtp_ice_turn_request (instance=instance at entry=0x7f41502a34b0, component=component at entry=AST_RTP_ICE_COMPONENT_RTCP, transport=transport at entry=AST_TRANSPORT_TCP, server=0x556f2b8cbab0 "10.144.31.1", port=0xd96, username=0x556f2b8cbac0 "<redacted>", password=0x556f2b8cbad0 "<redacted>") at res_rtp_asterisk.c:1686
#5  0x00007f417c0b4e81 in rtp_add_candidates_to_ice (instance=instance at entry=0x7f41502a34b0, rtp=rtp at entry=0x7f41502a7550, addr=<optimized out>, port=<optimized out>, component=component at entry=0x2, transport=transport at entry=0x1) at ./third-party/pjproject/source/pjlib/include/pj/string.h:284
#6  0x00007f417c0b584a in ast_rtp_prop_set (instance=0x7f41502a34b0, property=<optimized out>, value=<optimized out>) at res_rtp_asterisk.c:8265
#7  0x0000556f292d32e0 in ast_rtp_instance_set_prop (instance=0x7f41502a34b0, property=property at entry=AST_RTP_PROPERTY_RTCP, value=value at entry=0x1) at rtp_engine.c:711
#8  0x00007f417da8f6d8 in dialog_initialize_rtp (dialog=dialog at entry=0x7f415000a240) at chan_sip.c:6086
#9  0x00007f417daedd91 in dialog_initialize_rtp (dialog=0x7f415000a240) at chan_sip.c:19464
#10 check_peer_ok (p=p at entry=0x7f415000a240, of=<optimized out>, req=req at entry=0x7f414c7b0280, sipmethod=sipmethod at entry=0x5, addr=addr at entry=0x7f414c7b01f0, authpeer=authpeer at entry=0x7f414c7ae528, reliable=<optimized out>, uri2=<optimized out>, uri2 at entry=0x7f414c7ae2f0 "sip:*55 at default", calleridname=0x7f414c7ae370 "XiVO Assistant") at chan_sip.c:19464
#11 0x00007f417daef628 in check_user_full (p=p at entry=0x7f415000a240, req=req at entry=0x7f414c7b0280, sipmethod=sipmethod at entry=0x5, uri=uri at entry=0x7f41500091ff "sip:*55 at default", reliable=reliable at entry=XMIT_RELIABLE, addr=addr at entry=0x7f414c7b01f0, authpeer=<optimized out>, authpeer at entry=0x7f414c7ae528) at chan_sip.c:19587
#12 0x00007f417daf1b91 in handle_request_invite (p=p at entry=0x7f415000a240, req=req at entry=0x7f414c7b0280, addr=addr at entry=0x7f414c7b01f0, seqno=<optimized out>, recount=recount at entry=0x7f414c7b01a0, e=e at entry=0x7f41500091ff "sip:*55 at default", nounlock=<optimized out>, nounlock at entry=0x7f414c7b01a4) at chan_sip.c:26700
#13 0x00007f417daf902a in handle_incoming (p=0x7f415000a240, req=0x7f414c7b0280, addr=<optimized out>, recount=<optimized out>, nounlock=<optimized out>) at chan_sip.c:29267
#14 0x00007f417dafb468 in handle_request_do (req=req at entry=0x7f414c7b0280, addr=addr at entry=0x7f414c7b01f0) at chan_sip.c:29475
#15 0x00007f417dafcd5a in sipsock_read (id=<optimized out>, fd=<optimized out>, events=<optimized out>, ignore=<optimized out>) at chan_sip.c:29406
#16 0x0000556f2928aa48 in ast_io_wait (ioc=0x556f2bbe5040, howlong=<optimized out>) at io.c:297
#17 0x00007f417dad2aeb in do_monitor (data=data at entry=0x0) at chan_sip.c:30053
#18 0x0000556f2933a485 in dummy_start (data=<optimized out>) at utils.c:1299
#19 0x00007f419e89ffa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#20 0x00007f419e476eff in inotify_add_watch () at ../sysdeps/unix/syscall-template.S:78
#21 0x0000000000000000 in ?? ()

It seems parameter of ast_cond_timedwait is used incorrectly because it is absolute time when to wakeup, so it must be updated every loop iteration.
Now it is not updated and after first iteration timespec is in past an no ast_cod_timedwait does not sleep any more.

Moreover when I fixed timespec parameter and the thread did not use all CPU any more, I realized that waiting for TURN completely blocks SIP traffic processing. It is true for chan_sip, I do not know about chan_pjsip.

As a acceptable workaround I decided to wait only 2 sec for TURN server, to not block chan_sip thread. But maybe it is not correct solution.

The problem with incorrect timespec in ast_cond_timedwait repeats several times in res/res_rtp_asterisk.c

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