Summary: | ASTERISK-26186: res_pjsip_multihomed: Deadlock when finding message header | ||
Reporter: | Mateusz Kowalski (mkowalski) | Labels: | |
Date Opened: | 2016-07-11 07:59:15 | Date Closed: | |
Priority: | Major | Regression? | |
Status: | Open/New | Components: | Resources/res_pjsip_multihomed |
Versions: | 13.9.1 | Frequency of Occurrence | One Time |
Related Issues: | |||
Environment: | CentOS 7.2 (3.10.0-327.22.2.el7.x86_64) Asterisk 13.9.1 PJSIP 2.5.1 MariaDB-server 10.1.14 mysql-connector-odbc 5.3.6 | Attachments: | ( 0) trace1.txt ( 1) trace2.txt |
Description: | Hello,
I encountered a deadlock in PJSIP module. Two backtraces available as * http://pastebin.com/raw/kZtc5df3 (Thread 43) * http://pastebin.com/raw/93H9qe4x (Thread 42) Output from {{core show locks}} is empty: {code} tone-0058-re-1*CLI> core show locks ======================================================================= === 13.9.1 === Currently Held Locks ======================================================================= === === <pending> <lock#> (<file>): <lock type> <line num> <function> <lock name> <lock addr> (times locked) === ======================================================================= {code} Any packets arriving to the machine on port 5060 are left without any response. They are not visible in Asterisk console even with {{pjsip set logger on}} Output from {{netstat}} shows big RX queue for the process: {code} udp 214912 0 0.0.0.0:5060 0.0.0.0:* 46787/asterisk {code} If you check {{netstat}} per port, it happens also on RTP port (I'm using 10000-20000): {code} udp 0 0 0.0.0.0:2727 0.0.0.0:* 46787/asterisk udp 896 0 0.0.0.0:35859 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:37171 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:4520 0.0.0.0:* 46787/asterisk udp 214912 0 0.0.0.0:5060 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:10520 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:10521 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:11356 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:11357 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:12048 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:12049 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:12062 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:12063 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:13890 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:13891 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:14608 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:14609 0.0.0.0:* 46787/asterisk udp 213248 0 0.0.0.0:14678 0.0.0.0:* 46787/asterisk udp 34048 0 0.0.0.0:14679 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:14752 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:14753 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:15106 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:15107 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:18100 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:18101 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:18392 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:18393 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:18918 0.0.0.0:* 46787/asterisk udp 0 0 0.0.0.0:18919 0.0.0.0:* 46787/asterisk {code} Initially I reported issue on #asterisk but later on got redirected to open a ticket in here. Snaps of my configuration in here: {{asterisk.conf}} {code} [directories](!) astetcdir => /etc/asterisk astmoddir => /usr/lib/asterisk/modules astvarlibdir => /var/lib/asterisk astdbdir => /var/lib/asterisk astkeydir => /var/lib/asterisk astdatadir => /var/lib/asterisk astagidir => /var/lib/asterisk/agi-bin astspooldir => /var/spool/asterisk astrundir => /var/run/asterisk astlogdir => /var/log/asterisk astsbindir => /usr/sbin [options] ;verbose = 5 ;debug = 5 ;alwaysfork = yes ; Same as -F at startup. ;nofork = yes ; Same as -f at startup. ;quiet = yes ; Same as -q at startup. ;timestamp = yes ; Same as -T at startup. ;execincludes = yes ; Support #exec in config files. ;console = yes ; Run as console (same as -c at startup). ;highpriority = yes ; Run realtime priority (same as -p at ; startup). ;initcrypto = yes ; Initialize crypto keys (same as -i at ; startup). ;nocolor = yes ; Disable console colors. ;dontwarn = yes ; Disable some warnings. ;dumpcore = yes ; Dump core on crash (same as -g at startup). ;languageprefix = yes ; Use the new sound prefix path syntax. ;systemname = my_system_name ; Prefix uniqueid with a system name for ; Global uniqueness issues. ;autosystemname = yes ; Automatically set systemname to hostname, ; uses 'localhost' on failure, or systemname if ; set. ;mindtmfduration = 80 ; Set minimum DTMF duration in ms (default 80 ms) ; If we get shorter DTMF messages, these will be ; changed to the minimum duration ;maxcalls = 10 ; Maximum amount of calls allowed. ;maxload = 0.9 ; Asterisk stops accepting new calls if the ; load average exceed this limit. ;maxfiles = 1000 ; Maximum amount of openfiles. ;minmemfree = 1 ; In MBs, Asterisk stops accepting new calls if ; the amount of free memory falls below this ; watermark. ;cache_record_files = yes ; Cache recorded sound files to another ; directory during recording. ;record_cache_dir = /tmp ; Specify cache directory (used in conjunction ; with cache_record_files). ;transmit_silence = yes ; Transmit silence while a channel is in a ; waiting state, a recording only state, or ; when DTMF is being generated. Note that the ; silence internally is generated in raw signed ; linear format. This means that it must be ; transcoded into the native format of the ; channel before it can be sent to the device. ; It is for this reason that this is optional, ; as it may result in requiring a temporary ; codec translation path for a channel that may ; not otherwise require one. ;transcode_via_sln = yes ; Build transcode paths via SLINEAR, instead of ; directly. ;runuser = asterisk ; The user to run as. ;rungroup = asterisk ; The group to run as. ;lightbackground = yes ; If your terminal is set for a light-colored ; background. ;forceblackbackground = yes ; Force the background of the terminal to be ; black, in order for terminal colors to show ; up properly. ;defaultlanguage = en ; Default language documentation_language = en_US ; Set the language you want documentation ; displayed in. Value is in the same format as ; locale names. ;hideconnect = yes ; Hide messages displayed when a remote console ; connects and disconnects. ;lockconfdir = no ; Protect the directory containing the ; configuration files (/etc/asterisk) with a ; lock. ;stdexten = gosub ; How to invoke the extensions.conf stdexten. ; macro - Invoke the stdexten using a macro as ; done by legacy Asterisk versions. ; gosub - Invoke the stdexten using a gosub as ; documented in extensions.conf.sample. ; Default gosub. ;live_dangerously = no ; Enable the execution of 'dangerous' dialplan ; functions from external sources (AMI, ; etc.) These functions (such as SHELL) are ; considered dangerous because they can allow ; privilege escalation. ; Default no ; Changing the following lines may compromise your security. ;[files] ;astctlpermissions = 0660 ;astctlowner = root ;astctlgroup = apache ;astctl = asterisk.ctl {code} {{extensions.conf}} {code} [professional] switch => Realtime/professional@extensions [private] switch => Realtime/private@extensions [sigos] switch => Realtime/sigos@extensions {code} {{hep.conf}} {code} [general] enabled = yes capture_address = XXX:9060 ;capture_password = foo capture_id = 1234 {code} {{modules.conf}} {code} [modules] autoload=yes preload => res_odbc.so preload => res_config_odbc.so {code} {{pjsip.conf}} {code} [transport-udp] type=transport protocol=udp bind=0.0.0.0 {code} {{sorcery.conf}} {code} [res_pjsip] endpoint=realtime,ps_endpoints ;endpoint=config,pjsip.conf,criteria=type=endpoint ;auth=realtime,ps_auths aor=realtime,ps_aors ;aor=config,pjsip.conf,criteria=type=aor ;domain_alias=realtime,ps_domain_aliases ;contact=realtime,ps_contacts [res_pjsip_endpoint_identifier_ip] identify=realtime,ps_endpoint_id_ips ;identify=config,pjsip.conf,criteria=type=identify {code} {{/etc/odbc.ini}} {code} [asterisk] Driver = MySQL ODBC 5.3 Unicode Driver Description = MySQL connection to ‘asterisk’ database Server = localhost Port = 3306 Database = XXX UserName = XXX Password = XXX Socket = /mnt/mysqld/mysql.sock {code} {{/etc/odbcinst.ini}} {code} [MySQL ODBC 5.3 Unicode Driver] Driver=/usr/lib64/libmyodbc5w.so FileUsage = 1 Pooling = Yes CPTimeout = 120 {code} Thanks for any help, Mateusz | ||
Comments: | By: Asterisk Team (asteriskteam) 2016-07-11 07:59:15.692-0500 Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process]. By: Joshua C. Colp (jcolp) 2016-07-11 08:49:06.642-0500 Please attach backtraces as attachments so they are not lost. As well please provide the console output and configuration. By: Mateusz Kowalski (mkowalski) 2016-07-11 09:44:36.219-0500 Updated with config files and uploaded backtraces. I'm not attaching console output as during deadlock there is nothing in the output. By: Joshua C. Colp (jcolp) 2016-07-11 09:56:59.205-0500 While there's nothing going on when it deadlocks there is logging before it occurs, which may provide further insight into how it got there. It's best to give all the information you can when filing an issue so that the person who works on it does not have to ask for more if they need it, and it also makes it easier to find things. By: Mateusz Kowalski (mkowalski) 2016-07-11 10:02:45.347-0500 Asterisk logfile around the moment deadlock occured {code} [Jul 8 14:54:34] WARNING[95561][C-0000117a] res_rtp_asterisk.c: RTP Transmission error of packet to 137.138.34.223:32228: Operation not permitted [Jul 11 12:03:00] NOTICE[85699] sorcery.c: Type 'system' is not reloadable, maintaining previous values [Jul 11 12:06:09] Asterisk 13.9.1 built by root @ tone-0058-re-1.cern.ch on a x86_64 running Linux on 2016-07-01 13:00:59 UTC [Jul 11 12:06:09] NOTICE[147869] res_odbc.c: Registered ODBC class 'asterisk' dsn->[asterisk] [Jul 11 12:06:09] NOTICE[26978] sorcery.c: Type 'system' is not reloadable, maintaining previous values [Jul 11 12:06:09] ERROR[147869] ari/config.c: No configured users for ARI [Jul 11 12:06:09] NOTICE[147869] cel_custom.c: No mappings found in cel_custom.conf. Not logging CEL to custom CSVs. [Jul 11 12:06:09] NOTICE[147869] app_queue.c: queuerules.conf has not changed since it was last loaded. Not taking any action. {code} |