| Summary: | ASTERISK-25210: pjsip 'qualify_timeout' problem | ||||
| Reporter: | Marco Paland (mpaland) | Labels: | |||
| Date Opened: | 2015-06-29 08:49:41 | Date Closed: | 2015-07-10 07:32:41 | ||
| Priority: | Major | Regression? | No | ||
| Status: | Closed/Complete | Components: | Resources/res_pjsip | ||
| Versions: | 13.4.0 | Frequency of Occurrence | Constant | ||
| Related Issues: |
| ||||
| Environment: | debian derivate, asterisk 13.4.0 self compiled | Attachments: | ( 0) extensions.conf ( 1) myDebugLog ( 2) pjsip.conf | ||
| Description: | I'm having major problems after an update from 13.2.0 to actual 13.4.0 using the pjsip channel.
ALL pjsip endpoints (snom phone, SPA112) are not working in 13.4.0 anymore due a mysterious configuration problem. After reloading: {code} -- Registered extension context 'macro-strip-country-code'; registrar: pbx_config -- Added extension 's' priority 1 to macro-strip-country-code -- Added extension 's' priority 2 to macro-strip-country-code -- Added extension 's' priority 3 to macro-strip-country-code -- Added extension 's' priority 4 to macro-strip-country-code -- Added extension 's' priority 5 to macro-strip-country-code -- Added extension 's' priority 6 to macro-strip-country-code -- Added extension 's' priority 7 to macro-strip-country-code -- Added extension 's' priority 8 to macro-strip-country-code -- Added extension 's' priority 9 to macro-strip-country-code -- Registered extension context ''; registrar: SCCP -- merging incls/swits/igpats from old() to new() context, registrar = pbx_config -- Registered extension context '__func_periodic_hook_context__'; registrar: func_periodic_hook -- merging incls/swits/igpats from old(__func_periodic_hook_context__) to new(__func_periodic_hook_context__) context, registrar = pbx_config -- Added extension 'hook' priority 1 (CID match '') to __func_periodic_hook_context__ -- Added extension 'hook' priority 2 (CID match '') to __func_periodic_hook_context__ -- Added extension 'hook' priority 3 (CID match '') to __func_periodic_hook_context__ -- Added extension 'hook' priority 4 (CID match '') to __func_periodic_hook_context__ -- Added extension 'hook' priority 5 (CID match '') to __func_periodic_hook_context__ -- Added extension 'hook' priority 6 (CID match '') to __func_periodic_hook_context__ -- Added extension 'beep' priority 1 (CID match '') to __func_periodic_hook_context__ -- Added extension 'beep' priority 2 (CID match '') to __func_periodic_hook_context__ -- merging incls/swits/igpats from old(unauthenticated) to new(unauthenticated) context, registrar = pbx_config -- Time to scan old dialplan and merge leftovers back into the new: 0.000330 sec -- Time to restore hints and swap in new dialplan: 0.000097 sec -- Time to delete the old dialplan: 0.000212 sec -- Total time merge_contexts_delete: 0.000639 sec -- Reloading module 'chan_sccp.so' (Skinny Client Control Protocol (SCCP). Release: 4.2.0 RC3 - unknown (built by 'root' on '2015-06-08 09:32:10 UTC') -- ) == Parsing '/var/ipfire/asterisk/sccp.conf': Found [Jun 28 19:14:41] NOTICE[10952]: sccp_config.c:2522 sccp_config_getConfig: Config file 'sccp.conf' has not changed, aborting reload. [Jun 28 19:14:41] NOTICE[10952]: chan_sccp.c:752 sccp_reload: config file 'sccp.conf' has not change, skipping reload. -- Reloading module 'res_clialiases.so' (CLI Aliases) -- Reloading module 'app_minivm.so' (Mini VoiceMail (A minimal Voicemail e-mail System)) [Jun 28 19:14:41] WARNING[10952]: app_minivm.c:2877 load_config: Failed to load configuration file. Module activated with default settings. -- Reloading module 'app_playback.so' (Sound File Playback Application) -- Added contact 'sip:11@192.168.2.170:5060' to AOR '11' with expiration of 3600 seconds [Jun 28 19:26:10] ERROR[11581]: config_options.c:710 aco_process_var: Could not find option suitable for category '11;@sip:11@192.168.2.170:5060' named 'qualify_timeout' at line 0 of [Jun 28 19:26:10] ERROR[11586]: config_options.c:710 aco_process_var: Could not find option suitable for category '11;@sip:11@192.168.2.170:5060' named 'qualify_timeout' at line 0 of -- Added contact 'sip:30@192.168.2.170:5061' to AOR '30' with expiration of 3600 seconds [Jun 28 19:26:10] ERROR[11586]: config_options.c:710 aco_process_var: Could not find option suitable for category '30;@sip:30@192.168.2.170:5061' named 'qualify_timeout' at line 0 of [Jun 28 19:26:10] ERROR[11582]: config_options.c:710 aco_process_var: Could not find option suitable for category '30;@sip:30@192.168.2.170:5061' named 'qualify_timeout' at line 0 of Contact 11/sip:11@192.168.2.170:5060 is now Unavailable Contact 30/sip:30@192.168.2.170:5061 is now Unavailable CLI> database show /SCCP/SEP0015F/lastDialedNumber : 0211;lineInstance=1 /SCCP/SEP001DE/lastDialedNumber : 0521;lineInstance=1 /SCCP/SEP001E4/lastDialedNumber : 21;lineInstance=1 /SCCP/SEP00270/lastDialedNumber : 10;lineInstance=1 /dundi/secret : XS+hRvLh0BKi0s9mh /dundi/secretexpiry : 143008 6 results found. CLI> {code} But I don't have a "qualify_timeout" option anywhere in my config (what line "0" indicates) or in the database. Because of this error all endpoint sections are ignored and all endpoints are unavailable! I know that the qualify_timeout option is new to pjsip and should make this value variable - but there seems to be a bug. In the moment, 13.4.0 is not usable for us! Reverted back to 13.2.0 which is okay. | ||||
| Comments: | By: Asterisk Team (asteriskteam) 2015-06-29 08:49:43.362-0500 The severity of this issue has been automatically downgraded from "Blocker" to "Major". The "Blocker" severity is reserved for issues which have been determined to block the next release of Asterisk. This severity can only be set by privileged users. If this issue is deemed to block the next release it will be updated accordingly during the triage process. By: Asterisk Team (asteriskteam) 2015-06-29 08:49:44.009-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: Rusty Newton (rnewton) 2015-06-29 14:09:50.459-0500 We require additional debug to continue with triage of your issue. Please follow the instructions on the wiki [1] for how to collect debugging information from Asterisk. For expediency, where possible, attach the debug with a '.txt' file extension so that the debug will be usable for further analysis. Thanks! [1] https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information By: Rusty Newton (rnewton) 2015-06-29 14:10:44.130-0500 Make sure the log is gathered as described in the instructions and includes verbose and debug. Is all of your configuration read from the .conf files? What PJPROJECT version are you using? By: Marco Paland (mpaland) 2015-06-30 05:11:56.293-0500 I updated the log. All logging params are set according to the wiki, but actually there's not so much information. A reload produces no errors, so all config should be read correctly. The last two (SIP) entries in the database are deleted after some time. I'm using actual pjproject 2.4, self compiled. It's working fine with 13.2.0. By: Rusty Newton (rnewton) 2015-06-30 13:38:30.408-0500 It looks like you gathered debug from the console rather than from a log. It also appears as if you don't have the "DEBUG" channel going to the console. See "logger show channels" to check your loaded logger.conf configuration. Gathering the log after starting and stopping Asterisk would gather what we need and prevent you from having to mess with console output. Assuming that you have followed the wiki instructions. By: Marco Paland (mpaland) 2015-07-02 03:57:38.545-0500 Replaced the log file again with the log file according to the wiki. By: Joshua C. Colp (jcolp) 2015-07-06 06:44:49.668-0500 This appears to be environment specific. On load Asterisk outputs the following: {noformat} [Jul 2 10:44:13] ERROR[10813] config_options.c: XML Documentation for option 'rpid_immediate' in modules 'res_pjsip' not found! [Jul 2 10:44:14] ERROR[10813] config_options.c: XML Documentation for option 'qualify_timeout' in modules 'res_pjsip' not found! [Jul 2 10:44:14] ERROR[10813] config_options.c: XML Documentation for option 'qualify_timeout' in modules 'res_pjsip' not found! [Jul 2 10:44:14] ERROR[10813] config_options.c: XML Documentation for option 'endpoint_identifier_order' in modules 'res_pjsip' not found! [Jul 2 10:44:14] ERROR[10813] config_options.c: XML Documentation for option 'max_initial_qualify_time' in modules 'res_pjsip' not found! {noformat} This occurs because the documentation file available to Asterisk is for your old version. This file is installed by the "make install" process into the "/var/lib/asterisk/documentation" directory. I've just confirmed this works as expected. How are you installing Asterisk? By: Marco Paland (mpaland) 2015-07-10 07:27:45.937-0500 I'm quite doing a "make install" on the build machine but after that, a script copies all relevant files to the production machine. The /var/lib/asterisk/documentation directory was NOT seen as relevant, so it was still the old version. After updating this dir to the latest 13.4.0 files, all is working fine and as expected. My fault, didn't realized that this dir is such important for running asterisk. So, this ain't a bug, please close this issue. THANX A LOT, Joshua! Regards, Marco By: Joshua C. Colp (jcolp) 2015-07-10 07:32:41.859-0500 You're welcome, and happy Friday! | ||||