Hi,

I’m trying to get presence/subscription working with Asterisk 18.6.0
using PJSIP and having no success so far.

My setup is:

Asterisk -> Upstream VoIP Provider (this part works fine)

Connectivity on the LAN is IPv6, with TCP based signalling. TLS is not enabled. The server is locally accessible over IPv4 but the phones are set to prefer IPv6.

Multiple extensions are locally talking directly to Asterisk, on extensions 1001 through to 1005. Extension 1000 is the main inbound number.

Extensions 1001, 1002 and 1003 are Cisco 8865/8845 IP Phones running Multiplatform Firmware, 11.3.4 (latest available). Extensions 1004 and
1005 are Grandstream WP phones.

All phones are registering with Asterisk and calls inbound and outbound work just fine. What is not working and what I need help with, is the presence/subscription information which is not working on all of the handsets.

What I have set up on the Cisco phones is the following:

Disabled
Downstairs Cordless Handset
private
fnc=blf+sd;sub=1004@$PROXY;ext=1004@$PROXY

The $PROXY variable is defined as sip.reub.net which is the Asterisk hostname.

There are a few other presence lines as well, each phone has different target extensions it is tracking. The aim is that this should be showing the status of extension 1004 on the shared line key. The phone accepts this config but the line always shows that the device is available and not in a call, even if it is.

I am fairly sure this worked with chan_sip but has never worked with pjsip. It was some months ago that I changed things over between modules and this just hasn’t been a high priority to fix up to date.

Logs show:

Aug 14 22:54:41] ERROR[26606] res_pjsip.c: Could not create dialog with endpoint 1001. Invalid URI (PJSIP_EINVALIDURI)
[Aug 14 22:54:41] WARNING[26606] res_pjsip_pubsub.c: Unable to create dialog for SIP subscription
[Aug 14 22:54:41] WARNING[26606] res_pjsip_pubsub.c: Failed recreating
‘1001’ subscription: Could not create subscription tree.
[Aug 14 22:54:41] ERROR[26606] res_pjsip.c: Could not create dialog with endpoint 1002. Invalid URI (PJSIP_EINVALIDURI)
[Aug 14 22:54:41] WARNING[26606] res_pjsip_pubsub.c: Unable to create dialog for SIP subscription
[Aug 14 22:54:41] WARNING[26606] res_pjsip_pubsub.c: Failed recreating
‘1002’ subscription: Could not create subscription tree.
[Aug 14 22:54:41] ERROR[26606] res_pjsip.c: Could not create dialog with endpoint 1001. Invalid URI (PJSIP_EINVALIDURI)
[Aug 14 22:54:41] WARNING[26606] res_pjsip_pubsub.c: Unable to create dialog for SIP subscription

Debugs show this:

<--- Received SIP request (628 bytes) from TCP:[2403:5800:7700:6411::5]:5066 --->
SUBSCRIBE sip:1003@sip.reub.net SIP/2.0
Via: SIP/2.0/TCP [2403:5800:7700:6411::5]:5066;branch=z9hG4bK-8a5f8a6c From: “Reuben Farrelly’s Phone” ;tag=96894202b140ddb To:
Call-ID: 1eb5588-6f32a075@2403:5800:7700:6411::5
CSeq: 26191 SUBSCRIBE
Max-Forwards: 70
Contact: “Reuben Farrelly’s Phone”

Accept: multipart/related Accept: application/rlmi+xml Accept: application/dialog-info+xml Expires: 1800
Event: dialog User-Agent: Cisco-CP-8845-3PCC/11.3.4
Content-Length: 0
Supported: replaces, sec-agree, eventlist

<--- Transmitting SIP response (538 bytes) to TCP:[2403:5800:7700:6411::5]:5066 --->
SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP
[2403:5800:7700:6411::5]:5066;rport=5066;received=2403:5800:7700:6411::5;branch=z9hG4bK-8a5f8a6c Call-ID: 1eb5588-6f32a075@2403:5800:7700:6411::5
From: “Reuben Farrelly’s Phone” ;tag=96894202b140ddb To: ;tag=z9hG4bK-8a5f8a6c CSeq: 26191 SUBSCRIBE
WWW-Authenticate: Digest realm=”asterisk”,nonce=”x”,opaque=”54aa5d4217da2b11″,algorithm=md5,qop=”auth”
Server: Asterisk PBX 18.6.0
Content-Length: 0

<--- Received SIP request (887 bytes) from TCP:[2403:5800:7700:6411::5]:5066 --->
SUBSCRIBE sip:1003@sip.reub.net SIP/2.0
Via: SIP/2.0/TCP [2403:5800:7700:6411::5]:5066;branch=z9hG4bK-e18fdc9c From: “Reuben Farrelly’s Phone” ;tag=96894202b140ddb To:
Call-ID: 1eb5588-6f32a075@2403:5800:7700:6411::5
CSeq: 26192 SUBSCRIBE
Max-Forwards: 70
Authorization: Digest username=”1002″,realm=”asterisk”,nonce=”x”,uri=”sip:1003@sip.reub.net”,algorithm=MD5,response=”x”,opaque=”54aa5d4217da2b11″,qop=auth,nc=00000001,cnonce=”80ff50e8″
Contact: “Reuben Farrelly’s Phone”

Accept: multipart/related Accept: application/rlmi+xml Accept: application/dialog-info+xml Expires: 1800
Event: dialog User-Agent: Cisco-CP-8845-3PCC/11.3.4
Content-Length: 0
Supported: replaces, sec-agree, eventlist

<--- Transmitting SIP response (637 bytes) to TCP:[2403:5800:7700:6411::5]:5066 --->
SIP/2.0 200 OK
Via: SIP/2.0/TCP
[2403:5800:7700:6411::5]:5066;rport=5066;received=2403:5800:7700:6411::5;branch=z9hG4bK-e18fdc9c Call-ID: 1eb5588-6f32a075@2403:5800:7700:6411::5
From: “Reuben Farrelly’s Phone” ;tag=96894202b140ddb To: ;tag=5e48d14e-efda-4f73-b1e1-7dcbbe12e7c4
CSeq: 26192 SUBSCRIBE
Expires: 1800
Contact:
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub Server: Asterisk PBX 18.6.0
Content-Length: 0

<--- Transmitting SIP request (949 bytes) to TCP:[2403:5800:7700:6411::5]:5066 --->
NOTIFY sip:1002@[2403:5800:7700:6411::5]:5066;transport=tcp SIP/2.0
Via: SIP/2.0/TCP
[2403:5800:7700:6410::25]:5060;rport;branch=z9hG4bKPj21e9c122-5302-4c39-bee5-9ea0d97fd29c;alias From: ;tag=5e48d14e-efda-4f73-b1e1-7dcbbe12e7c4
To: “Reuben Farrelly’s Phone” ;tag=96894202b140ddb Contact:
Call-ID: 1eb5588-6f32a075@2403:5800:7700:6411::5
CSeq: 8775 NOTIFY
Event: dialog Subscription-State: active;expires=1799
Allow-Events: message-summary, presence, dialog, refer Max-Forwards: 70
User-Agent: Asterisk PBX 18.6.0
Content-Type: application/dialog-info+xml Content-Length: 258

<--- Received SIP response (396 bytes) from TCP:[2403:5800:7700:6411::5]:5066 --->
SIP/2.0 200 OK
To: “Reuben Farrelly’s Phone” ;tag=96894202b140ddb From: ;tag=5e48d14e-efda-4f73-b1e1-7dcbbe12e7c4
Call-ID: 1eb5588-6f32a075@2403:5800:7700:6411::5
CSeq: 8775 NOTIFY
Via: SIP/2.0/TCP
[2403:5800:7700:6410::25]:5060;branch=z9hG4bKPj21e9c122-5302-4c39-bee5-9ea0d97fd29c;alias Server: Cisco-CP-8845-3PCC/11.3.4
Content-Length: 0

The terminated> line stands out as something I would not expect.

The pjsip modules I have loaded are:

supercell*CLI> module show like res_pjsip Module Description Use Count Status Support Level res_pjsip.so Basic SIP resource
47 Running core res_pjsip_acl.so PJSIP ACL Resource
0 Running core res_pjsip_authenticator_digest.so PJSIP authentication resource
0 Running core res_pjsip_caller_id.so PJSIP Caller ID Support
1 Running core res_pjsip_config_wizard.so PJSIP Config Wizard
1 Running core res_pjsip_dialog_info_body_generator.so PJSIP Extension State Dialog Info+XML Pr 0 Running core res_pjsip_diversion.so PJSIP Add Diversion Header Support
1 Running core res_pjsip_dlg_options.so SIP OPTIONS in dialog handler
0 Running core res_pjsip_dtmf_info.so PJSIP DTMF INFO Support
0 Running core res_pjsip_empty_info.so PJSIP Empty INFO Support
0 Running core res_pjsip_endpoint_identifier_anonymous.so PJSIP Anonymous endpoint identifier 0 Running core res_pjsip_endpoint_identifier_ip.so PJSIP IP endpoint identifier
0 Running core res_pjsip_endpoint_identifier_user.so PJSIP username endpoint identifier
0 Running core res_pjsip_exten_state.so PJSIP Extension State Notifications
0 Running core res_pjsip_header_funcs.so PJSIP Header Functions
0 Running core res_pjsip_history.so PJSIP History
0 Running extended res_pjsip_logger.so PJSIP Packet Logger
0 Running core res_pjsip_messaging.so PJSIP Messaging Support
0 Running core res_pjsip_mwi.so PJSIP MWI resource
0 Running core res_pjsip_mwi_body_generator.so PJSIP MWI resource
0 Running core res_pjsip_nat.so PJSIP NAT Support
0 Running core res_pjsip_notify.so CLI/AMI PJSIP NOTIFY Support
0 Running core res_pjsip_one_touch_record_info.so PJSIP INFO One Touch Recording Support 0 Running core res_pjsip_outbound_authenticator_digest.so PJSIP authentication resource
0 Running core res_pjsip_outbound_publish.so PJSIP Outbound Publish Support
2 Running core res_pjsip_outbound_registration.so PJSIP Outbound Registration Support
0 Running core res_pjsip_path.so PJSIP Path Header Support
0 Running core res_pjsip_phoneprov_provider.so PJSIP Phoneprov Provider
0 Running extended res_pjsip_pidf_body_generator.so PJSIP Extension State PIDF Provider
0 Running core res_pjsip_pidf_digium_body_supplement.so PJSIP PIDF Sangoma presence supplement 0 Running core res_pjsip_pidf_eyebeam_body_supplement.so PJSIP PIDF Eyebeam supplement
0 Running core res_pjsip_publish_asterisk.so PJSIP Asterisk Event PUBLISH Support
0 Running core res_pjsip_pubsub.so PJSIP event resource
21 Running core res_pjsip_refer.so PJSIP Blind and Attended Transfer Suppor
1 Running core res_pjsip_registrar.so PJSIP Registrar Support
0 Running core res_pjsip_rfc3326.so PJSIP RFC3326 Support
0 Running core res_pjsip_sdp_rtp.so PJSIP SDP RTP/AVP stream handler
0 Running core res_pjsip_send_to_voicemail.so PJSIP REFER Send to Voicemail Support
0 Running core res_pjsip_session.so PJSIP Session resource
18 Running core res_pjsip_sips_contact.so UAC SIPS Contact support
0 Running core res_pjsip_stir_shaken.so PJSIP STIR/SHAKEN Module for Asterisk
0 Running core res_pjsip_t38.so PJSIP T.38 UDPTL Support
0 Running core res_pjsip_transport_websocket.so PJSIP WebSocket Transport Support
0 Running core res_pjsip_xpidf_body_generator.so PJSIP Extension State PIDF Provider
0 Running core
44 modules loaded supercell*CLI>

Asterisk loads quite cleanly too, no indication here:

[Aug 14 22:54:40] Asterisk 18.6.0 built by portage @ supercell on a x86_64 running Linux on 2021-08-14 11:00:12 UTC
[Aug 14 22:54:40] NOTICE[26578] loader.c: 306 modules will be loaded.
[Aug 14 22:54:40] NOTICE[26578] cdr.c: CDR simple logging enabled.
[Aug 14 22:54:40] WARNING[26578] res_phoneprov.c: Unable to find a valid server address or name.
[Aug 14 22:54:40] NOTICE[26578] res_smdi.c: No SMDI interfaces are available to listen on, not starting SMDI listener.
[Aug 14 22:54:40] NOTICE[26578] chan_skinny.c: Configuring skinny from skinny.conf
[Aug 14 22:54:40] ERROR[26578] ari/config.c: No configured users for ARI
[Aug 14 22:54:40] NOTICE[26578] confbridge/conf_config_parser.c: Adding default_menu menu to app_confbridge
[Aug 14 22:54:40] NOTICE[26578] cel_custom.c: No mappings found in cel_custom.conf. Not logging CEL to custom CSVs.
[Aug 14 22:54:40] WARNING[26578] loader.c: Some non-required modules failed to load.
[Aug 14 22:54:40] WARNING[26578] loader.c: Module ‘res_monitor’ has been loaded but may be removed in a future release. Its replacement is
‘app_mixmonitor’.
[Aug 14 22:54:40] WARNING[26578] loader.c: Module ‘res_adsi’ has been loaded but may be removed in a future release.
[Aug 14 22:54:40] WARNING[26578] loader.c: Module ‘app_url’ has been loaded but may be removed in a future release.
[Aug 14 22:54:40] WARNING[26578] loader.c: Module ‘app_adsiprog’ has been loaded but may be removed in a future release.
[Aug 14 22:54:40] WARNING[26578] loader.c: Module ‘app_image’ has been loaded but may be removed in a future release.
[Aug 14 22:54:41] WARNING[26578] loader.c: Module ‘app_nbscat’ has been loaded but may be removed in a future release.
[Aug 14 22:54:41] WARNING[26578] loader.c: Module ‘app_getcpeid’ has been loaded but may be removed in a future release.
[Aug 14 22:54:41] WARNING[26578] loader.c: Module ‘app_ices’ has been loaded but may be removed in a future release.
[Aug 14 22:54:41] ERROR[26578] loader.c: cel_sqlite3_custom declined to load.
[Aug 14 22:54:41] ERROR[26578] loader.c: cdr_syslog declined to load.
[Aug 14 22:54:41] ERROR[26578] loader.c: cdr_sqlite3_custom declined to load.

Basic endpoint config, same for all:

[1002]
; Reuben Phone type=endpoint context=default aors=1002
auth=1002-auth

disallow=all allow=h264
allow=g722
allow=alaw

[1002-auth]
type=auth auth_type=userpass username=1002
password=x

[1002]
type=aor max_contacts=10
remove_existing=yes qualify_frequency=15

and in extensions.conf:

ReubenFarrelly=PJSIP/1002
exten=>1002,1,Dial(PJSIP/${EXTEN})
exten=>1002,hint,PJSIP/1002

Can anyone help me determine why this might be failing or what debugs I
need to enable to determine the cause?

Thanks, Reuben

—