| Summary: | ASTERISK-24405: pjsip: assert after restart with tls | ||||
| Reporter: | Scott Griepentrog (sgriepentrog) | Labels: | |||
| Date Opened: | 2014-10-09 11:26:54 | Date Closed: | 2015-01-05 06:10:32.000-0600 | ||
| Priority: | Major | Regression? | |||
| Status: | Closed/Complete | Components: | pjproject/pjsip | ||
| Versions: | SVN 12.6.0 13.0.0-beta2 | Frequency of Occurrence | Frequent | ||
| Related Issues: |
| ||||
| Environment: | trunk-r424874 | Attachments: | |||
| Description: | 1) Yealink phone registered via TLS over NAT
2) CLI> originate pjsip/ext# application echo 3) Answer call, hang up 4) CLI> core restart now After some delay, an assert will fairly consistently occur. Presumably this is while the phone is attempting to re-establish registration. {noformat} asterisk: ../src/pj/ssl_sock_ossl.c:2420: pj_ssl_sock_send: Assertion `ssock->ssl_state==SSL_STATE_ESTABLISHED' failed. Program received signal SIGABRT, Aborted. [Switching to Thread 0x7fffb023f700 (LWP 705)] 0x00007ffff55135c9 in raise () from /lib64/libc.so.6 Missing separate debuginfos, use: debuginfo-install alsa-lib-1.0.27.2-3.el7.x86_64 glibc-2.17-55.el7_0.1.x86_64 jack-audio-connection-kit-1.9.9.5-4.el7.x 86_64 jansson-2.4-6.el7.x86_64 keyutils-libs-1.5.8-3.el7.x86_64 krb5-libs-1.11.3-49.el7.x86_64 libX11-1.6.0-2.1.el7.x86_64 libXau-1.0.8-2.1.el7.x86_64 li bcom_err-1.42.9-4.el7.x86_64 libgcc-4.8.2-16.2.el7_0.x86_64 libselinux-2.2.2-6.el7.x86_64 libsrtp-1.4.4-9.20101004cvs.el7.x86_64 libstdc++-4.8.2-16.2.el7 _0.x86_64 libuuid-2.23.2-16.el7.x86_64 libxcb-1.9-5.el7.x86_64 libxml2-2.9.1-5.el7.x86_64 ncurses-libs-5.9-13.20130511.el7.x86_64 nss-softokn-freebl-3.15 .4-2.el7.x86_64 openssl-libs-1.0.1e-34.el7_0.4.x86_64 opus-1.0.2-6.el7.x86_64 pcre-8.32-12.el7.x86_64 portaudio-19-16.el7.x86_64 speex-1.2-0.19.rc1.el7.x 86_64 sqlite-3.7.17-4.el7.x86_64 systemd-libs-208-11.el7_0.2.x86_64 xz-libs-5.1.2-8alpha.el7.x86_64 zlib-1.2.7-13.el7.x86_64 (gdb) bt #0 0x00007ffff55135c9 in raise () from /lib64/libc.so.6 #1 0x00007ffff5514cd8 in abort () from /lib64/libc.so.6 #2 0x00007ffff550c536 in __assert_fail_base () from /lib64/libc.so.6 #3 0x00007ffff550c5e2 in __assert_fail () from /lib64/libc.so.6 #4 0x00007fffb2f532fe in pj_ssl_sock_send () from /lib64/libpj.so.2 #5 0x00007ffff0fc88eb in tls_send_msg () from /lib64/libpjsip.so.2 #6 0x00007ffff0fc0ec5 in pjsip_transport_send () from /lib64/libpjsip.so.2 #7 0x00007ffff0fbe768 in pjsip_endpt_send_response () from /lib64/libpjsip.so.2 #8 0x00007ffff0fbe84c in pjsip_endpt_send_response2 () from /lib64/libpjsip.so.2 #9 0x00007fffb1d7f8cd in authenticate (rdata=<optimized out>) at res_pjsip/pjsip_distributor.c:318 #10 0x00007ffff0fbb427 in pjsip_endpt_process_rx_data () from /lib64/libpjsip.so.2 #11 0x00007fffb1d7f119 in distribute (data=0x7fff8c02c368) at res_pjsip/pjsip_distributor.c:349 #12 0x00000000005d3c95 in ast_taskprocessor_execute (tps=0x1843b88) at taskprocessor.c:769 #13 0x00000000005dd0cd in threadpool_execute (pool=0x1849628) at threadpool.c:351 #14 0x00000000005de5eb in worker_active (worker=0x7fffa8000cb8) at threadpool.c:1075 #15 0x00000000005de3a8 in worker_start (arg=0x7fffa8000cb8) at threadpool.c:995 #16 0x00000000005e9db0 in dummy_start (data=0x7fffa8000dd0) at utils.c:1201 #17 0x00007ffff62f3df3 in start_thread () from /lib64/libpthread.so.0 #18 0x00007ffff55d401d in clone () from /lib64/libc.so.6 (gdb) {noformat} | ||||
| Comments: | By: Scott Griepentrog (sgriepentrog) 2014-10-09 13:43:01.741-0500 It may be unrelated to the Yealink phone, but still TLS related. With debug on, the next time it asserted this is the last received message: {noformat} <--- Received SIP request (550 bytes) from TLS:216.207.245.1:51397 ---> OPTIONS sip:red.stg.net SIP/2.0 Call-ID: 5039b24981ca2b93efe965a0b2e535b3@0:0:0:0:0:0:0:0 CSeq: 2369 OPTIONS From: "205" <sip:205@red.stg.net>;tag=5a429d66 To: "205" <sip:205@red.stg.net> Via: SIP/2.0/TLS 10.24.22.236:51397;branch=z9hG4bK-373539-2a6dac19705bb680a2dae15ff92a7d04 Max-Forwards: 70 Contact: "205" <sip:205@10.24.22.236:51397;transport=tls;registering_acc=red_stg_net> User-Agent: Jitsi2.4.4997Windows 7 Allow: INFO,OPTIONS,MESSAGE,BYE,REFER,SUBSCRIBE,ACK,CANCEL,PUBLISH,NOTIFY,INVITE Allow-Events: refer Content-Length: 0 asterisk: ../src/pj/ssl_sock_ossl.c:2420: pj_ssl_sock_send: Assertion `ssock->ssl_state==SSL_STATE_ESTABLISHED' failed. Aborted {noformat} By: Joshua C. Colp (jcolp) 2015-01-04 09:13:48.499-0600 This occurs because of the following scenario: 1. Request comes in on event handler thread 2. Request gets dispatched to another thread 3. TLS connection is terminated and marked as such on event handler thread 4. Request is handled on worker thread 5. Handler creates response and sends it 6. TLS code asserts because connection is terminated The assertion triggered will be turned into a normal return if debugging is disabled. By: Matt Jordan (mjordan) 2015-01-04 09:21:26.240-0600 Any way we can check in step 5 whether or not the transport is in a valid state? By: Joshua C. Colp (jcolp) 2015-01-04 09:26:54.298-0600 Not really no. That information can't be queried, although a state callback is invoked on changes. It also only lessens the chance of it happening since the connection may terminate between the check and going further down into the stack (albeit unlikely). By: Joshua C. Colp (jcolp) 2015-01-04 09:28:33.901-0600 Apparently that structure is not opaque as I thought it was (some stuff is, some stuff isn't) so there is a boolean that can be checked. By: Joshua C. Colp (jcolp) 2015-01-05 06:10:22.130-0600 This has been changed from an assert to a normal check upstream: http://trac.pjsip.org/repos/changeset/4972 | ||||