[asterisk-users] Asterisk PJSIP Presence/Subscription Setup with Cisco and Grandstream Phones
Reuben Farrelly
reuben-asterisk-users at reub.net
Sat Aug 14 08:35:39 CDT 2021
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:
<Extension_5_ ua="na">Disabled</Extension_5_><!-- available options:
1|2|3|4|5|6|7|8|9|10|Disabled -->
<Short_Name_5_ ua="na">Downstairs Cordless Handset</Short_Name_5_>
<Share_Call_Appearance_5_ ua="na">private</Share_Call_Appearance_5_><!--
available options: private|shared -->
<Extended_Function_5_
ua="na">fnc=blf+sd;sub=1004@$PROXY;ext=1004@$PROXY</Extended_Function_5_>
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 at 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" <sip:1002 at sip.reub.net>;tag=96894202b140ddb
To: <sip:1003 at sip.reub.net>
Call-ID: 1eb5588-6f32a075 at 2403:5800:7700:6411::5
CSeq: 26191 SUBSCRIBE
Max-Forwards: 70
Contact: "Reuben Farrelly's Phone"
<sip:1002@[2403:5800:7700:6411::5]:5066;transport=tcp>
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 at 2403:5800:7700:6411::5
From: "Reuben Farrelly's Phone" <sip:1002 at sip.reub.net>;tag=96894202b140ddb
To: <sip:1003 at sip.reub.net>;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 at 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" <sip:1002 at sip.reub.net>;tag=96894202b140ddb
To: <sip:1003 at sip.reub.net>
Call-ID: 1eb5588-6f32a075 at 2403:5800:7700:6411::5
CSeq: 26192 SUBSCRIBE
Max-Forwards: 70
Authorization: Digest
username="1002",realm="asterisk",nonce="x",uri="sip:1003 at sip.reub.net",algorithm=MD5,response="x",opaque="54aa5d4217da2b11",qop=auth,nc=00000001,cnonce="80ff50e8"
Contact: "Reuben Farrelly's Phone"
<sip:1002@[2403:5800:7700:6411::5]:5066;transport=tcp>
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 at 2403:5800:7700:6411::5
From: "Reuben Farrelly's Phone" <sip:1002 at sip.reub.net>;tag=96894202b140ddb
To: <sip:1003 at sip.reub.net>;tag=5e48d14e-efda-4f73-b1e1-7dcbbe12e7c4
CSeq: 26192 SUBSCRIBE
Expires: 1800
Contact: <sip:[2403:5800:7700:6410::25]:5060;transport=TCP>
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: <sip:1003 at sip.reub.net>;tag=5e48d14e-efda-4f73-b1e1-7dcbbe12e7c4
To: "Reuben Farrelly's Phone" <sip:1002 at sip.reub.net>;tag=96894202b140ddb
Contact: <sip:[2403:5800:7700:6410::25]:5060;transport=TCP>
Call-ID: 1eb5588-6f32a075 at 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
<?xml version="1.0" encoding="UTF-8"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="0"
state="full" entity="sip:1003@[2403:5800:7700:6410::25]:5060;transport=TCP">
<dialog id="1003">
<state>terminated</state>
</dialog>
</dialog-info>
<--- Received SIP response (396 bytes) from
TCP:[2403:5800:7700:6411::5]:5066 --->
SIP/2.0 200 OK
To: "Reuben Farrelly's Phone" <sip:1002 at sip.reub.net>;tag=96894202b140ddb
From: <sip:1003 at sip.reub.net>;tag=5e48d14e-efda-4f73-b1e1-7dcbbe12e7c4
Call-ID: 1eb5588-6f32a075 at 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 <state>terminated><state> 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
More information about the asterisk-users
mailing list