[asterisk-bugs] [JIRA] (ASTERISK-26708) res_pjsip: ARI interface does not correctly indicate de-registrations
Rusty Newton (JIRA)
noreply at issues.asterisk.org
Mon Jan 9 20:23:09 CST 2017
[ https://issues.asterisk.org/jira/browse/ASTERISK-26708?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rusty Newton updated ASTERISK-26708:
------------------------------------
Affects Version/s: 14.2.1
> res_pjsip: 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, Resources/res_pjsip
> Affects Versions: 14.0.0, 14.2.1
> 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