Pjsip 'qualify_timeout' problem

I’m having major problems after an update from 13.2.0 to actual 13.4.0 using the pjsip channel.

ALL pjsip endpoints are not working in 13.4.0 anymore due a mysterious configuration problem.
After reloading:

[Jun 24 13:25:49] ERROR[30548]: 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 Contact 11/sip:11@192.168.2.170:5060 is now Unavailable

But I don’t have a “qualify_timeout” option anywhere in my config (what line “0” indicates).
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.

Does someone have the same issue?

What is the output of “database show” and what is the exact version you are using? The only time this would potentially come up is if you upgraded, stuff registered, then you downgraded.

An immediate fix would be to do “database deltree registrar/contact” from the CLI if not storing contacts in realtime.

Here is what the database contains:

CLI> database show /SCCP/SEP0015F92/lastDialedNumber : 0211;lineInstance=1 /SCCP/SEP001DE5E/lastDialedNumber : 0521;lineInstance=1 /SCCP/SEP001E4A0/lastDialedNumber : 21;lineInstance=1 /SCCP/SEP00270DB/lastDialedNumber : 10;lineInstance=1 /dundi/secret : XS+hRvLh0BKi0s9mhGdQFQ /dundi/secretexpiry : 1430082990 /registrar/contact/11;@sip:11@192.168.2.170:5060 : {"qualify_timeout":"0.000000","qualify_frequency":"0","outbound_proxy":"","expiration_time":"1435162143","path":"","uri":"sip:11@192.168.2.170:5060","user_agent":"Cisco/SPA112-1.3.5(004p_XU001)"} /registrar/contact/30;@sip:30@192.168.2.170:5061 : {"qualify_timeout":"0.000000","qualify_frequency":"0","outbound_proxy":"","expiration_time":"1435162143","path":"","uri":"sip:30@192.168.2.170:5061","user_agent":"Cisco/SPA112-1.3.5(004p_XU001)"} 8 results found.

I deleted the last two entries as you recommended and reregistered the SPA112. I get:

-- Added contact 'sip:11@192.168.2.170:5060' to AOR '11' with expiration of 3600 seconds [Jun 24 17:15:17] ERROR[13410]: 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 24 17:15:17] ERROR[13415]: 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

I just updated to 13.4.0, compiled from the actual sources.
I’m having the same behavior on two different systems. On the other system all snom phones are unavailable.

Extremely weird. It should be impossible for a device to register and add that, but for the code to not be able to read it back. Can you provide the complete console output?

Hi Joshua,
yes, it’s pretty weird.
Actually I provided the complete console output, other line are not important,IMHO.

[Jun 24 17:15:17] ERROR[13410]: 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 This really ends with “line 0 of”!

Really wondering why I have the same problem on two different systems and no one else is complaining/reporting any similar.

I see small snippets, but not a complete log.

As for line 0 - that’s normal.

Okay, here we go. The last part of the log after a reload:

-- 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>

Here is the according part from the pjsip.conf:[code];========= ENDPOINT TEMPLATES

endpoint-phone
type=endpoint
transport=transport-udp
inband_progress=yes
send_pai=true
device_state_busy_at=1
disallow=all
allow=g722
allow=alaw
allow=g726
allow=ulaw
allow=gsm
context=from-internal

auth-userpass
type=auth
auth_type=userpass

aor-single-reg
type=aor
max_contacts=1
remove_existing=yes

;========== EXTENSION 11

11
auth=auth11
aors=11
callerid=W <11>

auth11
username=11
password=xxx

11

;========== EXTENSION 30 FAX

30
auth=auth30
aors=30
callerid=FAX <30>
t38_udptl=yes
t38_udptl_ec=redundancy
disallow=all
allow=alaw

auth30
username=30
password=xxx

30
[/code]

I’d suggest posting this on the issue tracker[1] so it can be labbed up and isolated further.

[1] issues.asterisk.org/jira

Thanx, Joshua,

created ASTERISK-25210 for this issue.

Regards,
Marco