Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

SIP Websocket accept queue fills up - FS does not accept new connections any more #922

Closed
schrd opened this issue Oct 19, 2020 · 16 comments
Closed

SIP Websocket accept queue fills up - FS does not accept new connections any more #922

schrd opened this issue Oct 19, 2020 · 16 comments
Labels
bug Something isn't working

Comments

@schrd
Copy link

schrd commented Oct 19, 2020

Describe the bug
FS runs in a BigBlueButton setup behind a nginx reverse proxy. Connections are made through sofia websocket.

There are 65 connections between nginx and FS in CLOSE_WAIT state on the Freeswitch side of the connection. This did not change after a few hours. To my knowledge this means that connections are not correctly closed by Freeswitch. At the same time the TCP accept queue seems to be full:

ss --info --tcp --listen --extended|grep 7443
LISTEN     65     64     AAA.BBB.CCC.DDD:7443                     *:*                     uid:932 ino:16296 sk:1 <->

This leads to an unresponsive freeswitch. New connections using Sip over websocket are impossible. Connections to the event socket are possible.

To Reproduce
Unfortunately this problem occurs only on rare conditions, I do not know what is neccesary to reproduce this. However this problem is not a singular event, I observed it a few times in the past and other BigBlueButton users observed this as well. See bigbluebutton/bigbluebutton#9667

I created a core dump and extracted a stack trace.

Expected behavior
Freeswitch should serve websocket requests.

Package version or git hash

  • git version 133fc2c, running on Ubuntu 16.04, Packages from BigBlueButton.

Trace logs
Provide freeswitch logs w/ DEBUG and UUID logging enabled

backtrace from core file

Thread 40 (Thread 0x7f9082889700 (LWP 7612)):
#0  0x00007f90fb32680d in poll () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fbc04c80 in poll (__timeout=20, __nfds=1, __fds=0x7f9082882380) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  apr_poll (aprset=aprset@entry=0x7f8fe4055aa8, num=num@entry=1, nsds=nsds@entry=0x7f908288249c, timeout=20) at poll/unix/poll.c:117
#3  0x00007f90fb86d117 in switch_poll (aprset=0x7f8fe4055aa8, numsock=numsock@entry=1, nsds=nsds@entry=0x7f908288249c, timeout=<optimized out>) at src/switch_apr.c:1035
#4  0x00007f90fb9131e6 in read_rtp_packet (rtp_session=rtp_session@entry=0x7f8fe403e1d8, bytes=bytes@entry=0x7f9082882618, flags=flags@entry=0x7f90d4110ff0, pmapP=pmapP@entry=0x7f90d4111000, poll_status=poll_sta
tus@entry=SWITCH_STATUS_SUCCESS, return_jb_packet=SWITCH_TRUE) at src/switch_rtp.c:5850
#5  0x00007f90fb9154df in rtp_common_read (rtp_session=rtp_session@entry=0x7f8fe403e1d8, payload_type=payload_type@entry=0x7f90d4110fdc "", pmapP=pmapP@entry=0x7f90d4111000, flags=flags@entry=0x7f90d4110ff0, io_
flags=io_flags@entry=0) at src/switch_rtp.c:7436
#6  0x00007f90fb9168e6 in switch_rtp_zerocopy_read_frame (rtp_session=0x7f8fe403e1d8, frame=frame@entry=0x7f90d4110f98, io_flags=io_flags@entry=0) at src/switch_rtp.c:8123
#7  0x00007f90fb8c148d in switch_core_media_read_frame (session=session@entry=0x7f90d474fea8, frame=frame@entry=0x7f9082888ce0, flags=flags@entry=0, stream_id=stream_id@entry=0, type=type@entry=SWITCH_MEDIA_TYPE
_AUDIO) at src/switch_core_media.c:2919
#8  0x00007f90f18d4d80 in sofia_read_frame (session=0x7f90d474fea8, frame=0x7f9082888ce0, flags=0, stream_id=0) at mod_sofia.c:1170
#9  0x00007f90fb8a72ca in switch_core_session_read_frame (session=session@entry=0x7f90d474fea8, frame=frame@entry=0x7f9082888ce0, flags=flags@entry=0, stream_id=stream_id@entry=0) at src/switch_core_io.c:175
#10 0x00007f90f013cef4 in conference_loop_input (thread=<optimized out>, obj=0x7f908231da00) at conference_loop.c:843
#11 0x00007f90fbc04e65 in dummy_worker (opaque=0x7f8fe40fb790) at threadproc/unix/thread.c:151
#12 0x00007f90fb5fc6ba in start_thread (arg=0x7f9082889700) at pthread_create.c:333
#13 0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 39 (Thread 0x7f908200d700 (LWP 7611)):
#0  0x00007f90fb60551d in read () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fb969a87 in read (__nbytes=8, __buf=0x7f9082000c80, __fd=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44
#2  _timerfd_next (timer=timer@entry=0x7f9082000d30) at src/switch_time.c:486
#3  0x00007f90fb96a9b9 in timer_next (timer=0x7f9082000d30) at src/switch_time.c:856
#4  0x00007f90fb8863ee in switch_core_timer_next (timer=timer@entry=0x7f9082000d30) at src/switch_core_timer.c:74
#5  0x00007f90f012dd7f in conference_thread_run (thread=<optimized out>, obj=0x7f8fe4078008) at mod_conference.c:250
#6  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f8fe4078ce0) at threadproc/unix/thread.c:151
#7  0x00007f90fb5fc6ba in start_thread (arg=0x7f908200d700) at pthread_create.c:333
#8  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 38 (Thread 0x7f908231f700 (LWP 7609)):
#0  0x00007f90fb60551d in read () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fb969a87 in read (__nbytes=8, __buf=0x7f908231c2d0, __fd=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44
#2  _timerfd_next (timer=timer@entry=0x7f908231c3a0) at src/switch_time.c:486
#3  0x00007f90fb96a9b9 in timer_next (timer=0x7f908231c3a0) at src/switch_time.c:856
#4  0x00007f90fb8863ee in switch_core_timer_next (timer=timer@entry=0x7f908231c3a0) at src/switch_core_timer.c:74
#5  0x00007f90f013f24f in conference_loop_output (member=member@entry=0x7f908231da00) at conference_loop.c:1643
#6  0x00007f90f012d3f7 in conference_function (session=<optimized out>, data=<optimized out>) at mod_conference.c:2487
#7  0x00007f90fb8a1095 in switch_core_session_exec (session=session@entry=0x7f90d474fea8, application_interface=application_interface@entry=0xbccb18, arg=arg@entry=0x7f8fe4057060 "${vbridge}@cdquality") at src/s
witch_core_session.c:2891
#8  0x00007f90fb8a182f in switch_core_session_execute_application_get_flags (session=session@entry=0x7f90d474fea8, app=0x7f8fe4057050 "conference", arg=0x7f8fe4057060 "${vbridge}@cdquality", flags=flags@entry=0x
0) at src/switch_core_session.c:2756
#9  0x00007f90fb8a1c90 in switch_core_session_execute_exten (session=session@entry=0x7f90d474fea8, exten=<optimized out>, dialplan=<optimized out>, context=<optimized out>) at src/switch_core_session.c:3021
#10 0x00007f90cbbe4573 in exe_function (session=0x7f90d474fea8, data=<optimized out>) at mod_dptools.c:659
#11 0x00007f90fb8a1095 in switch_core_session_exec (session=session@entry=0x7f90d474fea8, application_interface=application_interface@entry=0xbc4508, arg=arg@entry=0x7f90280013f0 "ECHO_TO_CONFERENCE XML default"
) at src/switch_core_session.c:2891
#12 0x00007f90fb8a182f in switch_core_session_execute_application_get_flags (session=session@entry=0x7f90d474fea8, app=app@entry=0x7f9028001370 "execute_extension", arg=arg@entry=0x7f90280013f0 "ECHO_TO_CONFEREN
CE XML default", flags=flags@entry=0x0) at src/switch_core_session.c:2756
#13 0x00007f90fb95160e in switch_ivr_parse_event (session=session@entry=0x7f90d474fea8, event=<optimized out>) at src/switch_ivr.c:646
#14 0x00007f90fb951e6b in switch_ivr_parse_next_event (session=session@entry=0x7f90d474fea8) at src/switch_ivr.c:802
#15 0x00007f90fb951fdc in switch_ivr_parse_all_events (session=session@entry=0x7f90d474fea8) at src/switch_ivr.c:937
#16 0x00007f90fb93886f in switch_ivr_session_echo (session=0x7f90d474fea8, args=args@entry=0x0) at src/switch_ivr_async.c:729
#17 0x00007f90cbbe2d21 in echo_function (session=<optimized out>, data=<optimized out>) at mod_dptools.c:2321
#18 0x00007f90fb8a1095 in switch_core_session_exec (session=session@entry=0x7f90d474fea8, application_interface=application_interface@entry=0xbc5ff0, arg=arg@entry=0x7f90fbc17a2e "") at src/switch_core_session.c:2891
#19 0x00007f90fb8a182f in switch_core_session_execute_application_get_flags (session=session@entry=0x7f90d474fea8, app=0x7f8fe400c0b8 "echo", arg=0x7f90fbc17a2e "", flags=flags@entry=0x0) at src/switch_core_session.c:2756
#20 0x00007f90fb8a2bc6 in switch_core_standard_on_execute (session=session@entry=0x7f90d474fea8) at src/switch_core_state_machine.c:354
#21 0x00007f90fb8a5a75 in switch_core_session_run (session=0x7f90d474fea8) at src/switch_core_state_machine.c:651
#22 0x00007f90fb89e70d in switch_core_session_thread (thread=<optimized out>, obj=0x7f90d474fea8) at src/switch_core_session.c:1709
#23 0x00007f90fb89a16d in switch_core_session_thread_pool_worker (thread=0x7f90d4164120, obj=<optimized out>) at src/switch_core_session.c:1772
#24 0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90d4164120) at threadproc/unix/thread.c:151
#25 0x00007f90fb5fc6ba in start_thread (arg=0x7f908231f700) at pthread_create.c:333
#26 0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 37 (Thread 0x7f9083549700 (LWP 54512)):
#0  0x00007f90fb32680d in poll () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fbc04c80 in poll (__timeout=20, __nfds=1, __fds=0x7f9083548080) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  apr_poll (aprset=aprset@entry=0x7f90684bb0a0, num=num@entry=1, nsds=nsds@entry=0x7f9083548188, timeout=20, timeout@entry=20000) at poll/unix/poll.c:117
#3  0x00007f90fb86d117 in switch_poll (aprset=0x7f90684bb0a0, numsock=numsock@entry=1, nsds=nsds@entry=0x7f9083548188, timeout=timeout@entry=20000) at src/switch_apr.c:1035
#4  0x00007f90f1b72af8 in read_packet (listener=listener@entry=0x7f906800b9d8, event=event@entry=0x7f90835487f0, timeout=timeout@entry=0) at mod_event_socket.c:1496
#5  0x00007f90f1b77c62 in listener_run (thread=<optimized out>, obj=0x7f906800b9d8) at mod_event_socket.c:2756
#6  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90684bb258) at threadproc/unix/thread.c:151
#7  0x00007f90fb5fc6ba in start_thread (arg=0x7f9083549700) at pthread_create.c:333
#8  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 36 (Thread 0x7f9083383700 (LWP 1982)):
#0  0x00007f90fb32680d in poll () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fbc04c80 in poll (__timeout=20, __nfds=1, __fds=0x7f9083382080) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  apr_poll (aprset=aprset@entry=0x7f90834476b0, num=num@entry=1, nsds=nsds@entry=0x7f9083382188, timeout=20, timeout@entry=20000) at poll/unix/poll.c:117
#3  0x00007f90fb86d117 in switch_poll (aprset=0x7f90834476b0, numsock=numsock@entry=1, nsds=nsds@entry=0x7f9083382188, timeout=timeout@entry=20000) at src/switch_apr.c:1035
#4  0x00007f90f1b72af8 in read_packet (listener=listener@entry=0x7f9068009878, event=event@entry=0x7f90833827f0, timeout=timeout@entry=0) at mod_event_socket.c:1496
#5  0x00007f90f1b77c62 in listener_run (thread=<optimized out>, obj=0x7f9068009878) at mod_event_socket.c:2756
#6  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f9083447868) at threadproc/unix/thread.c:151
#7  0x00007f90fb5fc6ba in start_thread (arg=0x7f9083383700) at pthread_create.c:333
#8  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 35 (Thread 0x7f90c8092700 (LWP 1764)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fbbf7554 in apr_queue_pop (queue=queue@entry=0xce30e0, data=data@entry=0x7f90c8091e48) at misc/apr_queue.c:276
#3  0x00007f90fb86d38b in switch_queue_pop (queue=queue@entry=0xce30e0, data=data@entry=0x7f90c8091e48) at src/switch_apr.c:1159
#4  0x00007f90fb8f3558 in chat_thread_run (thread=<optimized out>, obj=0xce30e0) at src/switch_loadable_module.c:946
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0xcef0d0) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90c8092700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 34 (Thread 0x7f9083fc3700 (LWP 1763)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fbbf7554 in apr_queue_pop (queue=queue@entry=0xab25f0, data=data@entry=0x7f9083fc2e48) at misc/apr_queue.c:276
#3  0x00007f90fb86d38b in switch_queue_pop (queue=queue@entry=0xab25f0, data=data@entry=0x7f9083fc2e48) at src/switch_apr.c:1159
#4  0x00007f90fb8f3558 in chat_thread_run (thread=<optimized out>, obj=0xab25f0) at src/switch_loadable_module.c:946
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0xce30b0) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f9083fc3700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 33 (Thread 0x7f9083fff700 (LWP 1762)):
#0  0x00007f90fb60551d in read () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fb96b865 in read (__nbytes=8, __buf=0x7f9083ffedc8, __fd=65) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44
#2  softtimer_runtime () at src/switch_time.c:1176
#3  0x00007f90fb8eb5c0 in switch_loadable_module_exec (thread=0xab2570, obj=0xab2150) at src/switch_loadable_module.c:123
#4  0x00007f90fbc04e65 in dummy_worker (opaque=0xab2570) at threadproc/unix/thread.c:151
#5  0x00007f90fb5fc6ba in start_thread (arg=0x7f9083fff700) at pthread_create.c:333
#6  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 32 (Thread 0x7f90c8056700 (LWP 1761)):
#0  0x00007f90fb60576d in accept () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fbc039c6 in apr_socket_accept (new=new@entry=0x7f90c8055e08, sock=0x7f9068002bd0, connection_context=0x7f90680070f8) at network_io/unix/sockets.c:195
#2  0x00007f90fb86cb8d in switch_socket_accept (new_sock=new_sock@entry=0x7f90c8055e08, sock=<optimized out>, pool=<optimized out>) at src/switch_apr.c:745
#3  0x00007f90f1b74cab in mod_event_socket_runtime () at mod_event_socket.c:3010
#4  0x00007f90fb8eb5c0 in switch_loadable_module_exec (thread=0xab20b8, obj=0xab1c98) at src/switch_loadable_module.c:123
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0xab20b8) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90c8056700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 31 (Thread 0x7f9083f87700 (LWP 1760)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fb86c5a2 in switch_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at src/switch_apr.c:371
#3  0x00007f90f0624d93 in mod_verto_runtime () at mod_verto.c:6275
#4  0x00007f90fb8eb5c0 in switch_loadable_module_exec (thread=0xab1c00, obj=0xab16e0) at src/switch_loadable_module.c:123
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0xab1c00) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f9083f87700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 30 (Thread 0x7f90ca71c700 (LWP 1754)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fb86c5a2 in switch_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at src/switch_apr.c:371
#3  0x00007f90ca729580 in timer_thread_run (thread=<optimized out>, obj=<optimized out>) at mod_spandsp_fax.c:220
#4  0x00007f90fbc04e65 in dummy_worker (opaque=0xc74798) at threadproc/unix/thread.c:151
#5  0x00007f90fb5fc6ba in start_thread (arg=0x7f90ca71c700) at pthread_create.c:333
#6  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 29 (Thread 0x7f90cb6b0700 (LWP 1753)):
#0  0x00007f90fb328693 in select () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fbc064b8 in apr_sleep (t=<optimized out>) at time/unix/time.c:246
#2  0x00007f90fb9697ad in do_sleep (t=<optimized out>) at src/switch_time.c:164
#3  0x00007f90fb96c275 in switch_sleep (t=t@entry=1000000) at src/switch_time.c:643
#4  0x00007f90cb7c1f13 in node_thread_run (thread=<optimized out>, obj=<optimized out>) at mod_fifo.c:2181
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0xc0a968) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90cb6b0700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 28 (Thread 0x7f90cb6ec700 (LWP 1750)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fb86c5a2 in switch_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at src/switch_apr.c:371
#3  0x00007f90fb89298a in switch_user_sql_thread (thread=<optimized out>, obj=0xc2ff10) at src/switch_core_sqldb.c:2354
#4  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90cb7b06c0) at threadproc/unix/thread.c:151
#5  0x00007f90fb5fc6ba in start_thread (arg=0x7f90cb6ec700) at pthread_create.c:333
#6  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 27 (Thread 0x7f90f0117700 (LWP 1727)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fbbf7554 in apr_queue_pop (queue=0xb47728, data=data@entry=0x7f90f0116e40) at misc/apr_queue.c:276
#3  0x00007f90fb86d38b in switch_queue_pop (queue=<optimized out>, data=data@entry=0x7f90f0116e40) at src/switch_apr.c:1159
#4  0x00007f90f192bc89 in sofia_presence_event_thread_run (thread=<optimized out>, obj=<optimized out>) at sofia_presence.c:1624
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0xb484d8) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f0117700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 26 (Thread 0x7f90f05ce700 (LWP 1724)):
#0  0x00007f90fb32680d in poll () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fb8fa673 in poll (__timeout=100, __nfds=3, __fds=0x7f908c011ca0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  switch_wait_socklist (waitlist=waitlist@entry=0x7f90f05cbc30, len=len@entry=3, ms=ms@entry=100) at src/switch_utils.c:3115
#3  0x00007f90f0625773 in profile_one_loop (profile=profile@entry=0x7f90f05f3038) at mod_verto.c:4433
#4  0x00007f90f0625b59 in runtime (profile=profile@entry=0x7f90f05f3038) at mod_verto.c:4556
#5  0x00007f90f0625be7 in profile_thread (thread=<optimized out>, obj=0x7f90f05f3038) at mod_verto.c:5194
#6  0x00007f90fb89a16d in switch_core_session_thread_pool_worker (thread=0xbb4810, obj=<optimized out>) at src/switch_core_session.c:1772
#7  0x00007f90fbc04e65 in dummy_worker (opaque=0xbb4810) at threadproc/unix/thread.c:151
#8  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f05ce700) at pthread_create.c:333
#9  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 25 (Thread 0x7f90f0c82700 (LWP 1614)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
#1  0x00007f90fbbff231 in apr_thread_cond_timedwait (cond=0x7f90f18c3b68, mutex=0x7f90f18c3b18, timeout=timeout@entry=100000) at locks/unix/thread_cond.c:89
#2  0x00007f90fbbf7646 in apr_queue_pop_timeout (queue=0x7f90f18c3ad8, data=data@entry=0x7f90f0c81e18, timeout=timeout@entry=100000) at misc/apr_queue.c:339
#3  0x00007f90fb86d399 in switch_queue_pop_timeout (queue=<optimized out>, data=data@entry=0x7f90f0c81e18, timeout=timeout@entry=100000) at src/switch_apr.c:1164
#4  0x00007f90f18fe29a in sofia_profile_worker_thread_run (thread=<optimized out>, obj=0xb57670) at sofia.c:3022
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f110fb40) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f0c82700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 24 (Thread 0x7f90f0cbe700 (LWP 1613)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
#1  0x00007f90fbbff231 in apr_thread_cond_timedwait (cond=0x7f90f18c3b68, mutex=0x7f90f18c3b18, timeout=timeout@entry=100000) at locks/unix/thread_cond.c:89
#2  0x00007f90fbbf7646 in apr_queue_pop_timeout (queue=0x7f90f18c3ad8, data=data@entry=0x7f90f0cbde18, timeout=timeout@entry=100000) at misc/apr_queue.c:339
#3  0x00007f90fb86d399 in switch_queue_pop_timeout (queue=<optimized out>, data=data@entry=0x7f90f0cbde18, timeout=timeout@entry=100000) at src/switch_apr.c:1164
#4  0x00007f90f18fe29a in sofia_profile_worker_thread_run (thread=<optimized out>, obj=0xb5d6a0) at sofia.c:3022
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f10acb40) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f0cbe700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 23 (Thread 0x7f90f0cfa700 (LWP 1612)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fb86c5a2 in switch_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at src/switch_apr.c:371
#3  0x00007f90fb89298a in switch_user_sql_thread (thread=<optimized out>, obj=0x7f90e0030ed0) at src/switch_core_sqldb.c:2354
#4  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f0dfa6c0) at threadproc/unix/thread.c:151
#5  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f0cfa700) at pthread_create.c:333
#6  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 22 (Thread 0x7f90f0d36700 (LWP 1611)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fb86c5a2 in switch_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at src/switch_apr.c:371
#3  0x00007f90fb89298a in switch_user_sql_thread (thread=<optimized out>, obj=0x7f90d4030ed0) at src/switch_core_sqldb.c:2354
#4  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f0ebf6c0) at threadproc/unix/thread.c:151
#5  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f0d36700) at pthread_create.c:333
#6  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 21 (Thread 0x7f90f114c700 (LWP 1610)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
#1  0x00007f90fbbff231 in apr_thread_cond_timedwait (cond=0x7f90f18c3b68, mutex=0x7f90f18c3b18, timeout=timeout@entry=100000) at locks/unix/thread_cond.c:89
#2  0x00007f90fbbf7646 in apr_queue_pop_timeout (queue=0x7f90f18c3ad8, data=data@entry=0x7f90f114be18, timeout=timeout@entry=100000) at misc/apr_queue.c:339
#3  0x00007f90fb86d399 in switch_queue_pop_timeout (queue=<optimized out>, data=data@entry=0x7f90f114be18, timeout=timeout@entry=100000) at src/switch_apr.c:1164
#4  0x00007f90f18fe29a in sofia_profile_worker_thread_run (thread=<optimized out>, obj=0xb636d0) at sofia.c:3022
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f13b0b40) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f114c700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 20 (Thread 0x7f90f1188700 (LWP 1609)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fb86c5a2 in switch_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at src/switch_apr.c:371
#3  0x00007f90fb89298a in switch_user_sql_thread (thread=<optimized out>, obj=0x7f90d8030ed0) at src/switch_core_sqldb.c:2354
#4  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f124c6c0) at threadproc/unix/thread.c:151
#5  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f1188700) at pthread_create.c:333
#6  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 19 (Thread 0x7f90f134e700 (LWP 1608)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
#1  0x00007f90fbbff231 in apr_thread_cond_timedwait (cond=0x7f90f18c3b68, mutex=0x7f90f18c3b18, timeout=timeout@entry=100000) at locks/unix/thread_cond.c:89
#2  0x00007f90fbbf7646 in apr_queue_pop_timeout (queue=0x7f90f18c3ad8, data=data@entry=0x7f90f134de18, timeout=timeout@entry=100000) at misc/apr_queue.c:339
#3  0x00007f90fb86d399 in switch_queue_pop_timeout (queue=<optimized out>, data=data@entry=0x7f90f134de18, timeout=timeout@entry=100000) at src/switch_apr.c:1164
#4  0x00007f90f18fe29a in sofia_profile_worker_thread_run (thread=<optimized out>, obj=0xb69700) at sofia.c:3022
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f1617b58) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f134e700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 18 (Thread 0x7f90f13ef700 (LWP 1607)):
#0  0x00007f90fb332ad3 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90faf82795 in su_epoll_port_wait_events () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#2  0x00007f90faf7eb02 in su_base_port_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#3  0x00007f90faf7ac29 in su_port_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#4  0x00007f90faf7bd77 in su_root_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#5  0x00007f90faf7f931 in su_pthread_port_clone_main () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f13ef700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 17 (Thread 0x7f90f142b700 (LWP 1606)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fb86c5a2 in switch_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at src/switch_apr.c:371
#3  0x00007f90fb89298a in switch_user_sql_thread (thread=<optimized out>, obj=0x7f90cc030f00) at src/switch_core_sqldb.c:2354
#4  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f14ef6c0) at threadproc/unix/thread.c:151
#5  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f142b700) at pthread_create.c:333
#6  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 16 (Thread 0x7f90f16d2700 (LWP 1597)):
#0  0x00007f90fb332ad3 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90faf82795 in su_epoll_port_wait_events () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#2  0x00007f90faf7eb02 in su_base_port_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#3  0x00007f90faf7ac29 in su_port_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#4  0x00007f90faf7bd77 in su_root_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#5  0x00007f90faf7f931 in su_pthread_port_clone_main () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f16d2700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 15 (Thread 0x7f90f1694700 (LWP 1596)):
#0  0x00007f90fb332ad3 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90faf82795 in su_epoll_port_wait_events () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#2  0x00007f90faf7eb02 in su_base_port_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#3  0x00007f90faf7ac29 in su_port_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#4  0x00007f90faf7bd77 in su_root_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#5  0x00007f90faf7f931 in su_pthread_port_clone_main () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f1694700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 14 (Thread 0x7f90f1656700 (LWP 1595)):
#0  0x00007f90fb60551d in read () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90f8ca26dc in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
#2  0x00007f90f8ca067c in BIO_read () from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0
#3  0x00007f90f8ff962a in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
#4  0x00007f90f8ffaecd in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
#5  0x00007f90f8ff7a84 in ?? () from /lib/x86_64-linux-gnu/libssl.so.1.0.0
#6  0x00007f90fafa6802 in ws_raw_read () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#7  0x00007f90fafa7317 in ws_read_frame () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#8  0x00007f90fafa43cf in tport_recv_stream_ws () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#9  0x00007f90faf96d33 in tport_recv_data () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#10 0x00007f90faf96dda in tport_recv_event () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#11 0x00007f90faf96b08 in tport_base_wakeup () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#12 0x00007f90faf969da in tport_wakeup () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#13 0x00007f90faf828ba in su_epoll_port_wait_events () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#14 0x00007f90faf7eb02 in su_base_port_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#15 0x00007f90faf7ac29 in su_port_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#16 0x00007f90faf7bd77 in su_root_run () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#17 0x00007f90faf7f931 in su_pthread_port_clone_main () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#18 0x00007f90fb5fc6ba in start_thread (arg=0x7f90f1656700) at pthread_create.c:333
#19 0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 13 (Thread 0x7f90f170e700 (LWP 1591)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fbbf7554 in apr_queue_pop (queue=queue@entry=0x7f90f1860ad8, data=data@entry=0x7f90f170de38) at misc/apr_queue.c:276
#3  0x00007f90fb86d38b in switch_queue_pop (queue=queue@entry=0x7f90f1860ad8, data=data@entry=0x7f90f170de38) at src/switch_apr.c:1159
#4  0x00007f90f1919574 in sofia_msg_thread_run (thread=<optimized out>, obj=0x7f90f1860ad8) at sofia.c:2311
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0xb571d0) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f170e700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 12 (Thread 0x7f90f174a700 (LWP 1590)):
#0  0x00007f90fb332ad3 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90faf82795 in su_epoll_port_wait_events () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#2  0x00007f90faf7ec93 in su_base_port_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#3  0x00007f90faf7ac8c in su_port_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#4  0x00007f90faf7be3e in su_root_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#5  0x00007f90f1909b6b in sofia_profile_thread_run (thread=<optimized out>, obj=0xb69700) at sofia.c:3422
#6  0x00007f90fbc04e65 in dummy_worker (opaque=0xb6b918) at threadproc/unix/thread.c:151
#7  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f174a700) at pthread_create.c:333
#8  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 11 (Thread 0x7f90f1786700 (LWP 1589)):
#0  0x00007f90fb332ad3 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90faf82795 in su_epoll_port_wait_events () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#2  0x00007f90faf7ec93 in su_base_port_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#3  0x00007f90faf7ac8c in su_port_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#4  0x00007f90faf7be3e in su_root_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#5  0x00007f90f1909b6b in sofia_profile_thread_run (thread=<optimized out>, obj=0xb636d0) at sofia.c:3422
#6  0x00007f90fbc04e65 in dummy_worker (opaque=0xb657f8) at threadproc/unix/thread.c:151
#7  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f1786700) at pthread_create.c:333
#8  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 10 (Thread 0x7f90f17c2700 (LWP 1588)):
#0  0x00007f90fb332ad3 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90faf82795 in su_epoll_port_wait_events () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#2  0x00007f90faf7ec93 in su_base_port_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#3  0x00007f90faf7ac8c in su_port_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#4  0x00007f90faf7be3e in su_root_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#5  0x00007f90f1909b6b in sofia_profile_thread_run (thread=<optimized out>, obj=0xb5d6a0) at sofia.c:3422
#6  0x00007f90fbc04e65 in dummy_worker (opaque=0xb5f988) at threadproc/unix/thread.c:151
#7  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f17c2700) at pthread_create.c:333
#8  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 9 (Thread 0x7f90f17fe700 (LWP 1587)):
#0  0x00007f90fb332ad3 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90faf82795 in su_epoll_port_wait_events () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#2  0x00007f90faf7ec93 in su_base_port_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#3  0x00007f90faf7ac8c in su_port_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#4  0x00007f90faf7be3e in su_root_step () from /opt/freeswitch/lib/libsofia-sip-ua.so.0
#5  0x00007f90f1909b6b in sofia_profile_thread_run (thread=<optimized out>, obj=0xb57670) at sofia.c:3422
#6  0x00007f90fbc04e65 in dummy_worker (opaque=0xb59820) at threadproc/unix/thread.c:151
#7  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f17fe700) at pthread_create.c:333
#8  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 8 (Thread 0x7f90f2827700 (LWP 1434)):
#0  0x00007f90fb328693 in select () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fbc064b8 in apr_sleep (t=<optimized out>) at time/unix/time.c:246
#2  0x00007f90fb9697ad in do_sleep (t=<optimized out>) at src/switch_time.c:164
#3  0x00007f90fb96c275 in switch_sleep (t=t@entry=1000000) at src/switch_time.c:643
#4  0x00007f90fb898bcf in switch_core_sql_db_thread (thread=<optimized out>, obj=<optimized out>) at src/switch_core_sqldb.c:1600
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f2ea17b8) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f2827700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 7 (Thread 0x7f90f2b79700 (LWP 1433)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fb86c5a2 in switch_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at src/switch_apr.c:371
#3  0x00007f90fb89298a in switch_user_sql_thread (thread=<optimized out>, obj=0xb31b30) at src/switch_core_sqldb.c:2354
#4  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f28eb6c0) at threadproc/unix/thread.c:151
#5  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f2b79700) at pthread_create.c:333
#6  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 6 (Thread 0x7f90f2bb7700 (LWP 1414)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
#1  0x00007f90fbbff231 in apr_thread_cond_timedwait (cond=0xaa75b8, mutex=0xaa7568, timeout=timeout@entry=500000) at locks/unix/thread_cond.c:89
#2  0x00007f90fbbf7646 in apr_queue_pop_timeout (queue=0xaa7528, data=data@entry=0x7f90f2bb6e48, timeout=timeout@entry=500000) at misc/apr_queue.c:339
#3  0x00007f90fb86d399 in switch_queue_pop_timeout (queue=<optimized out>, data=data@entry=0x7f90f2bb6e48, timeout=timeout@entry=500000) at src/switch_apr.c:1164
#4  0x00007f90fb8e9d5e in switch_scheduler_task_thread (thread=<optimized out>, obj=<optimized out>) at src/switch_scheduler.c:191
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f2da05d8) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f2bb7700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 5 (Thread 0x7f90f2ddd700 (LWP 1409)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fbbf7554 in apr_queue_pop (queue=0x7f90f302fec8, data=data@entry=0x7f90f2ddce48) at misc/apr_queue.c:276
#3  0x00007f90fb86d38b in switch_queue_pop (queue=<optimized out>, data=data@entry=0x7f90f2ddce48) at src/switch_apr.c:1159
#4  0x00007f90fb95ef29 in log_thread (t=<optimized out>, obj=<optimized out>) at src/switch_log.c:470
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f2ea15a8) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f2ddd700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 4 (Thread 0x7f90f2ede700 (LWP 1408)):
#0  0x00007f90fb32680d in poll () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fb8fa673 in poll (__timeout=100, __nfds=2, __fds=0x7f9098069390) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  switch_wait_socklist (waitlist=waitlist@entry=0x7f90f2edbc30, len=len@entry=2, ms=ms@entry=100) at src/switch_utils.c:3115
#3  0x00007f90f0625773 in profile_one_loop (profile=profile@entry=0x7f90f05cf038) at mod_verto.c:4433
#4  0x00007f90f0625b59 in runtime (profile=profile@entry=0x7f90f05cf038) at mod_verto.c:4556
#5  0x00007f90f0625be7 in profile_thread (thread=<optimized out>, obj=0x7f90f05cf038) at mod_verto.c:5194
#6  0x00007f90fb89a16d in switch_core_session_thread_pool_worker (thread=0xa9d440, obj=<optimized out>) at src/switch_core_session.c:1772
#7  0x00007f90fbc04e65 in dummy_worker (opaque=0xa9d440) at threadproc/unix/thread.c:151
#8  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f2ede700) at pthread_create.c:333
#9  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 3 (Thread 0x7f90f2fa6700 (LWP 1130)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f90fbbff1b7 in apr_thread_cond_wait (cond=<optimized out>, mutex=<optimized out>) at locks/unix/thread_cond.c:68
#2  0x00007f90fbbf7554 in apr_queue_pop (queue=queue@entry=0x900638, data=data@entry=0x7f90f2fa5e38) at misc/apr_queue.c:276
#3  0x00007f90fb86d38b in switch_queue_pop (queue=queue@entry=0x900638, data=data@entry=0x7f90f2fa5e38) at src/switch_apr.c:1159
#4  0x00007f90fb8fe9bb in switch_event_dispatch_thread (thread=0x7f90f302fc40, obj=0x900638) at src/switch_event.c:328
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90f302fc40) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90f2fa6700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 2 (Thread 0x7f90fc02b700 (LWP 1128)):
#0  0x00007f90fb328693 in select () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fbc064b8 in apr_sleep (t=<optimized out>) at time/unix/time.c:246
#2  0x00007f90fb9697ad in do_sleep (t=<optimized out>) at src/switch_time.c:164
#3  0x00007f90fb96c275 in switch_sleep (t=t@entry=1000000) at src/switch_time.c:643
#4  0x00007f90fb889722 in pool_thread (thread=<optimized out>, obj=<optimized out>) at src/switch_core_memory.c:634
#5  0x00007f90fbc04e65 in dummy_worker (opaque=0x7f90fc08dc40) at threadproc/unix/thread.c:151
#6  0x00007f90fb5fc6ba in start_thread (arg=0x7f90fc02b700) at pthread_create.c:333
#7  0x00007f90fb3324dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 1 (Thread 0x7f90fc0f37c0 (LWP 1127)):
#0  0x00007f90fb328693 in select () at ../sysdeps/unix/syscall-template.S:84
#1  0x00007f90fbc064b8 in apr_sleep (t=<optimized out>) at time/unix/time.c:246
#2  0x00007f90fb9697ad in do_sleep (t=<optimized out>) at src/switch_time.c:164
#3  0x00007f90fb96c275 in switch_sleep (t=t@entry=1000000) at src/switch_time.c:643
#4  0x00007f90fb8ace8f in switch_core_runtime_loop (bg=bg@entry=1) at src/switch_core.c:1186
#5  0x00000000004041c3 in main (argc=7, argv=0x7fff927aa068) at src/switch.c:1227

I keep the core file, sources and binary from Freeswitch, let me know if I can provide anything to help to track this down. Thank you.
@schrd schrd added the bug Something isn't working label Oct 19, 2020
@schrd
Copy link
Author

schrd commented Oct 19, 2020

For debugging purposes I created a file every minute containing the output of

/opt/freeswitch/bin/fs_cli -x "show channels"|tee -a "$file"
netstat -putan | grep -i "7443\|5066\|5060"|tee -a "$file"

when I grep | wc these files for CLOSE_WAIT, I can see that the number of CLOSE_WAIT connections is piling up:

09:15:01 0
09:16:01 0
09:17:01 0
09:18:01 1
09:19:01 2
09:20:01 2
09:21:01 6
09:22:01 13
09:23:01 20
09:24:01 27
09:25:01 34
09:26:01 38
09:27:01 42
09:28:01 47
09:29:01 54
09:30:01 59
09:31:01 65 <-- starting from here connections were rejected
09:32:01 65
09:33:01 65
09:34:01 65
09:35:01 65

In the freeswitch log there is nothing obvious indicating a problem. Is there anything I should look for?

@invokablegmbh
Copy link

invokablegmbh commented Nov 21, 2020 •
edited
Loading

In the meantime there is some new information in the mentioned BBB issue that might help getting the root cause of this. So I will quickly summarize here:

  • The BBB constellation has an nginx reverse proxy in the middle (Client -> nginx -> freeswitch).
  • The error does happen, if we pass through the traffic to the SSL endpoint of freeswitch (e.g. on 7443).
  • The error does NOT happen, if we use the unencrypted endpoint of freeswitch (e.g. on 5066). So Client->nginx is SSL encrypted, whereas locally nginx->freeswitch is not.

So chances are that this is a bug in freeswitch's handling of ssl connections.

@tornad
Copy link

tornad commented Jul 16, 2021

Same behaviour HERE. Exactly the same description and system stop answer socket connection at 64 CLOSE_WAIT.

$ netstat -anp TCP | grep 7443 | grep CLOSE_WAIT   | wc -l
64

I think it's FS side too because if we connect directly to the port to check certificate expiration date, the connexion doesn't work and nothing answer.

$ echo | openssl s_client -connect wss02.xxxxxx.com:7443 2>/dev/null | openssl x509 -noout -enddate
<HERE LOT OF TIME, ABOUT 1 min>
unable to load certificate
4514651756:error:09FFF06C:PEM routines:CRYPTO_internal:no start line:/AppleInternal/BuildRoot/Library/Caches/com.apple.xbs/Sources/libressl/libressl-47.140.1/libressl-2.8/crypto/pem/pem_lib.c:684:Expecting: TRUSTED CERTIFICATE

I see the incoming request coming to the host via tcpdump but no answer from FS
And nothing with sofia loglevel all 9 it's like FS not handling the incoming request.
Finaly, the curl stop in timeout.

then, I tried to stop and start profile internal.
After that, All the CLOSED_WAIT socket was gone, and REGISTER works again.

And then, openssl works too.

$ echo | openssl s_client -connect wss02.xxxxxx.com:7443 2>/dev/null | openssl x509 -noout -enddate
<ONLY 1 SECOND>
notAfter=Dec  1 23:59:59 2021 GMT

@2954456878
Copy link

与此同时，在提到的BBB问题中有一些新的信息可能有助于获得此问题的根本原因。所以我会在这里快速总结一下：

  • BBB星座中间有一个nginx反向代理（客户端->nginx->自由开关）。
  • 如果我们通过流量传递到freeswitch的SSL端点（例如在7443上），则确实会发生错误。
  • 如果我们使用freeswitch的未加密端点（例如在5066上），则不会发生错误。因此，Client->nginx是SSL加密的，而本地nginx->freeswitch则不是。

因此，这可能是freeswitch处理ssl连接时的一个错误。

Same behaviour HERE，Is it really solved in this way？

@jerry6021
Copy link

This still seems to be happening - the WSS socket seems to stop reading from the socket.. see: freeswitch/sofia-sip#177

@jerry6021
Copy link

I have been able to reproduce the issue a little more reliably tonight.

Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 1 0 A.B.C.D:7443 0.0.0.0:* LISTEN 12462/freeswitch

The Recv-Q gets to 1 plus and the websocket thread stops... I have to restart FS to correct.
The pure SIP based phones continue to work without and noticable impact.

the webphones, using WSS are done - FS is simply not receiving the packets.

I'm wondering if there is some buffer overflow happening... That'll have to wait a few days

@jerry6021
Copy link

jerry6021 commented Oct 5, 2022 •
edited
Loading

A moment ago, FS stopped talking to the IPv4 clients (5060/7080/7443)

The ESL (8021) and the IPv6 ports seem OK.

I got some 1006 errors on the javascript side...

I waited 10 minutes but it did not correct itself.

Wed 05 Oct 2022 09:53:37 AM EDT
Proto Recv-Q Send-Q Local Address   Foreign Address         State       PID/Program name
tcp       27      0 [IP v4]:7080    0.0.0.0:*               LISTEN      25442/freeswitch
tcp       15      0 [IP v4]:5060    0.0.0.0:*               LISTEN      25442/freeswitch
tcp       65      0 [IP v4]:7443    0.0.0.0:*               LISTEN      25442/freeswitch
tcp        0      0 0.0.0.0:8021    0.0.0.0:*               LISTEN      25442/freeswitch
tcp6       0      0 [IP V6]:5060    :::*                    LISTEN      25442/freeswitch
tcp6       0      0 [IP V6]:7443    :::*                    LISTEN      25442/freeswitch

This is with the latest libsofia-sip-au lib 1.13.9

@jerry6021
Copy link

does anyone have FS 1.10.6 with the latest libsofia-sip-au and ctxSIP working over WSS ?

@fkakiman
Copy link

we have exactly the same issue with FS 1.10.6 and libsofia 1.13.9 with WSS handled by FS
all the tcp connections have a Recv-Q growing and became CLOSE_WAIT after a moment
sometimes it work again after a few minutes but most of the time we should do a FS restart

we do not have any solution for the moment :(
it happens randomly and disconnect everybody

@fkakiman
Copy link

someone has experienced this issue with the latest release of FS ? is it solved in this ?

@robertoscarpone
Copy link

I confirm that the problem is still there.
I created an issue a few days ago #1934

@bit4bit
Copy link

bit4bit commented Mar 21, 2023

hi, confirm the same problem, may this can help,
you can see the close-wait between nginx <-> freeswitch (7480)

FreeSWITCH (Version 1.10.8 -release.14 64bit) is ready

State      Recv-Q Send-Q Local Address:Port     Peer Address:Port Process
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:58386       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:58378       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:41654       
CLOSE-WAIT 586    0          127.0.0.1:7480        127.0.0.1:38728       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:45936       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:58394       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:42686       
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:53894       
CLOSE-WAIT 1      0       10.81.83.199:45260  pbx2:80          
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:59428       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:35354       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:57752       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:38542       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:58390       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:37448       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:52484       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:54714       
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:53708       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:45924       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:56326       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:56338       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:39284       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:57398       
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:54702       
CLOSE-WAIT 1      0       10.81.83.199:42490  pbx2:80          
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:42672       
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:47056       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:55326       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:35382       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:50532       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:46972       
CLOSE-WAIT 554    0          127.0.0.1:7480        127.0.0.1:55412       
CLOSE-WAIT 554    0          127.0.0.1:7480        127.0.0.1:42674       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:57382       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:39046       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:52456       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:34092       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:36612       
CLOSE-WAIT 554    0          127.0.0.1:7480        127.0.0.1:40546       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:42556       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:46974       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:50526       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:58404       
CLOSE-WAIT 554    0          127.0.0.1:7480        127.0.0.1:52452       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:42942       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:39288       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:38732       
CLOSE-WAIT 554    0          127.0.0.1:7480        127.0.0.1:35370       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:57808       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:53724       
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:52468       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:46150       
CLOSE-WAIT 586    0          127.0.0.1:7480        127.0.0.1:57770       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:45720       
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:45948       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:57764       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:50486       
CLOSE-WAIT 613    0          127.0.0.1:7480        127.0.0.1:55400       
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:38538       
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:55320       
CLOSE-WAIT 1      0       10.81.83.199:46320      pbx:80          
CLOSE-WAIT 1      0       10.81.83.199:45886      pbx:80          
CLOSE-WAIT 225    0          127.0.0.1:7480        127.0.0.1:46134       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:41834       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:59558       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:45958       
CLOSE-WAIT 552    0          127.0.0.1:7480        127.0.0.1:57812

@jerry6021
Copy link

jerry6021 commented Mar 21, 2023 via email

@fkakiman
Copy link

Hi
do you think there would be a workaround soon ? because it is a very impacted bug

@themsley-voiceflex themsley-voiceflex mentioned this issue Oct 19, 2023
Closed
@themsley-voiceflex
Copy link

This can probably be closed, duplicate of #2283

@andywolk
Copy link
Contributor

Fixed by freeswitch/sofia-sip#233

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
10 participants
@schrd @bit4bit @tornad @invokablegmbh @andywolk @robertoscarpone @jerry6021 @themsley-voiceflex @2954456878 @fkakiman