[asterisk-bugs] [JIRA] (ASTERISK-26708) ARI interface does not correctly indicate de-registrations
Andreas Rottmann (JIRA)
noreply at issues.asterisk.org
Mon Jan 9 08:02:10 CST 2017
Andreas Rottmann created ASTERISK-26708:
-------------------------------------------
Summary: ARI interface does not correctly indicate de-registrations
Key: ASTERISK-26708
URL: https://issues.asterisk.org/jira/browse/ASTERISK-26708
Project: Asterisk
Issue Type: Bug
Security Level: None
Components: Channels/chan_pjsip
Affects Versions: 14.0.0
Environment: Debian GNU/Linux stretch
Reporter: Andreas Rottmann
When a SIP user agent deregisters from Asterisk, the event that is sent out via ARI does *not* indicate that the endpoint is no longer available, in fact, it is undistinguishable from the event that is sent out when a UA registers.
This is a real issue when multiple endpoints are connected to a single peer, as it is no longer possible to reliably detect de-registrations. If there is only a single endpoint, one can work around the issue by processing the
{{PeerStatusChange}} message.
More specifically, the endpoint is indicated as "online", even though the event is published during de-registration. The CLI log (correctly) notes the endpoint as unreachable.
The following logs are taken with the following sequence of actions:
- Asterisk running with a CLI console. No endpoints are registered.
- A single endpoint is registered, and de-registered again. I'm using pjsua as user agent here.
- wscat is registered as a "Stasis Application".
The following output shows that, upon deregistration, ARI reports "contact_status" being "online" in the {{ContactStatus}} message. The following {{PeerStatusChange}} seems OK ("offline"), but this is not suitable for tracking individual endpoints.
{noformat}
% wscat -c 'ws://stretch-amd64-dev:8088/ari/events?api_key=asterisk:secret&app=rotty&subscribeAll=true'
< {"type":"ContactStatusChange","timestamp":"2017-01-09T12:07:20.089+0000","endpoint":{"technology":"PJSIP","resource":"rotty01","state":"offline","channel_ids":[]},"contact_info":{"uri":"sip:rotty01 at 10.200.0.10:5060","contact_status":"Created","aor":"rotty01","roundtrip_usec":"0"},"asterisk_id":"00:16:3e:08:f0:11","application":"rotty"}
< {"type":"PeerStatusChange","timestamp":"2017-01-09T12:07:20.116+0000","endpoint":{"technology":"PJSIP","resource":"rotty01","state":"online","channel_ids":[]},"peer":{"peer_status":"Reachable"},"asterisk_id":"00:16:3e:08:f0:11","application":"rotty"}
< {"type":"DeviceStateChanged","application":"rotty","timestamp":"2017-01-09T12:07:20.117+0000","device_state":{"name":"PJSIP/rotty01","state":"NOT_INUSE"},"asterisk_id":"00:16:3e:08:f0:11"}
< {"type":"ContactStatusChange","timestamp":"2017-01-09T12:07:20.121+0000","endpoint":{"technology":"PJSIP","resource":"rotty01","state":"online","channel_ids":[]},"contact_info":{"uri":"sip:rotty01 at 10.200.0.10:5060","contact_status":"Reachable","aor":"rotty01","roundtrip_usec":"3921"},"asterisk_id":"00:16:3e:08:f0:11","application":"rotty"}
[---- client disconnects here ----]
< {"type":"ContactStatusChange","timestamp":"2017-01-09T12:07:30.219+0000","endpoint":{"technology":"PJSIP","resource":"rotty01","state":"online","channel_ids":[]},"contact_info":{"uri":"sip:rotty01 at 10.200.0.10:5060","contact_status":"Reachable","aor":"rotty01","roundtrip_usec":"3921"},"asterisk_id":"00:16:3e:08:f0:11","application":"rotty"}
< {"type":"PeerStatusChange","timestamp":"2017-01-09T12:07:30.247+0000","endpoint":{"technology":"PJSIP","resource":"rotty01","state":"offline","channel_ids":[]},"peer":{"peer_status":"Unreachable"},"asterisk_id":"00:16:3e:08:f0:11","application":"rotty"}
< {"type":"DeviceStateChanged","application":"rotty","timestamp":"2017-01-09T12:07:30.247+0000","device_state":{"name":"PJSIP/rotty01","state":"UNAVAILABLE"},"asterisk_id":"00:16:3e:08:f0:11"}
{noformat}
The CLI output, as mentioned, looks reasonable:
{noformat}
== Contact rotty01/sip:rotty01 at 10.200.0.10:5060 has been created
== Endpoint rotty01 is now Reachable
== Contact rotty01/sip:rotty01 at 10.200.0.10:5060 has been deleted
== Endpoint rotty01 is now Unreachable
{noformat}
I've started digging into this in the Asterisk codebase; I'll summarize what I've gathered so far. The following is to be taken with several grains of salt, as this is the first serious look I took into the Asterisk code.
- Asterisk does not send the event with the proper contact status; the contact is indicated as "reachable". It does not seem the endpoint status is even updated during deregistration (verified by inserting a debug message into {{update_contact_status()}} in {{res/res_pjsip/pjsip_options.c}}.
- During deregistration {{persistent_endpoint_contact_deleted_observer()}} in {{res/res_pjsip/pjsip_configuration.c}} is invoked, which seems to be responsible for pushing the update out. However, {{contact_status->status}} is {{AVAILABLE}} at that point.
- Backtrace from {{contactstatus_to_json()}}, which emits the faulty event (line numbers may be off due to debugging statements I inserted in the code).
{noformat}
#0 contactstatus_to_json (msg=0x7fca28008d98, sanitize=0x7fca4e3358f0 <app_sanitizer>) at stasis_endpoints.c:253
#1 0x00005555b6b092a3 in stasis_message_to_json (msg=0x7fca28008d98, sanitize=0x7fca4e3358f0 <app_sanitizer>) at stasis_message.c:195
#2 0x00007fca4e123467 in sub_default_handler (data=0x7fc9d8001b38, sub=0x7fc9d8002508, message=0x7fca28008d98) at stasis/app.c:348
#3 0x00005555b6b09a1e in router_dispatch (data=0x7fc9d8002458, sub=0x7fc9d8002508, message=0x7fca28008d98) at stasis_message_router.c:201
#4 0x00005555b6af4644 in subscription_invoke (sub=0x7fc9d8002508, message=0x7fca28008d98) at stasis.c:434
#5 0x00005555b6af544d in dispatch_exec_async (local=0x7fc9e4c44c20) at stasis.c:715
#6 0x00005555b6b1729f in ast_taskprocessor_execute (tps=0x7fc9d8002668) at taskprocessor.c:965
#7 0x00005555b6b1519f in default_tps_processing_function (data=0x7fc9d80025e8) at taskprocessor.c:185
#8 0x00005555b6b2dbf3 in dummy_start (data=0x7fc9d8002750) at utils.c:1230
#9 0x00007fcadd752464 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#10 0x00007fcadc35e9df in clone () from /lib/x86_64-linux-gnu/libc.so.6
{noformat}
The contact needs to be updated during de-registration, but exactly how is not clear to me. I'm aware it's almost certainly wrong to just change the {{status}} field, both due to the multithreaded nature of Asterisk and from an architectural standpoint.
The {{update_contact_status()}} in {{res_pjsip/pjsip_options.c}} function seems to perform the update, but:
- The function is in another file, marked as {{static}}.
- It is not clear if the way that function performs the update is applicable in the context of de-registration.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list