Best practice regarding subscriptions

[mtryfoss]

Hello, and thanks for a really nice lib!

I got a question regarding subscription of channel events. It seems like a normal channelhandle.Subscribe() adds a subscription to "ari.event.." against NATS.

On a heavily used Asterisk node that will cause a lot of duplicate MSG's from NATS which then is discarded by the client (not belonging to me..).

Is it possible to make ari-proxy publish channel-messages on a subject for that channel only?

[Ulexus]

It is true that there will be duplicate messages, but that is not nearly as heavy as you might think at first glance.

First, we never copy the data for the duplicates; they are always just references.

Next, we only decode each message once and unless otherwise required, we only decode it enough to determine the type of Event.

Between these two things, it is actually very little overhead to have a large number of duplicates.

[Ulexus]

Please do let me know if you find a bottleneck here, but we have run some quite large installations without any constraints of this type.

[mtryfoss]

The current setup is about 700 concurrent calls (many long-lasting), and there's some indication of exponential growth of CPU usage compared to calls. 6 processes running the app, and that is using about 80% of one CPU core. However, there might be other parts of the code causing the load.

However, I see you're stating "we only decode it enough to determine the type of Event". I have one subscription to "ari.Events.All" and filtering what I need in a switch. That might be bad.

I'll have to dig more into it. Just wanted a quick feedback :)

[Ulexus]

I definitely would avoid using ari.Events.All. Asterisk produces a lot of events, many of them closely clustered. Subscribe() takes multiple events as an option, and I'd use them. Also, because subscriptions on handles are scoped to those handles, I can often get away with not decoding the complete events at all: just use the channel as a trigger.

Another common issue is goroutine leaks. There are various strategies to reduce the likelihood of these, but the first thing, really, is to figure out where your load is coming from.

Are you familiar with pprof? That's a great tool for profiling your app and seeing where it is spending most of its time.

https://golang.org/pkg/net/http/pprof/
https://blog.golang.org/profiling-go-programs

[Ulexus]

I should also mention that we do support a concept called "dialogs." The naming comes from a previous intention of retaining compatibility with nvisibleinc's ari proxy. In our case, a dialog is really a tag which is applied to certain resources which causes the server to send events for those resources to a different NATS subject. This will have the result of reducing client traffic load on heavily-loaded machines. To use them, just set the Dialog parameter (arbitrary string) on any resource key before sending that key to the proxy server. The server will automatically register it and tag events related to it. The client will automatically switch its subscription over to the NATS subject for that dialog.

I have never actually had to use this in production, but the feature is there, and it is basically what you asked at the beginning. I'd still profile your app before diving into dialogs (which are much less tested than anything else in the package).

[mtryfoss]

I'm pretty sure goroutines are under control. Did a lot of QA on this subject during development.

Ran pprof now, but while the system is relatively idle.

Top 10:
      flat  flat%   sum%        cum   cum%
     910ms 11.43% 11.43%      960ms 12.06%  encoding/json.stateInString
     650ms  8.17% 19.60%     1530ms 19.22%  encoding/json.checkValid
     530ms  6.66% 26.26%     1020ms 12.81%  encoding/json.(*decodeState).scanWhile
     330ms  4.15% 30.40%      450ms  5.65%  runtime.scanobject
     270ms  3.39% 33.79%      610ms  7.66%  encoding/json.(*decodeState).skip
     250ms  3.14% 36.93%     4460ms 56.03%  encoding/json.(*decodeState).object
     240ms  3.02% 39.95%      240ms  3.02%  encoding/json.unquoteBytes
     200ms  2.51% 42.46%      260ms  3.27%  encoding/json.stateEndValue
     170ms  2.14% 44.60%      910ms 11.43%  runtime.mallocgc
     160ms  2.01% 46.61%      160ms  2.01%  runtime.futex

So, it's seems like narrowing the subscriptions is probably the first step.

I will do some more testing and try an improved version in production during the coming week.

I'm using SetVariable() several places during each call mainly to manipulate SIP headers. I guess this will wait for a ChannelVarset event before return? It seems like this is one of the causes for the massive event generation.

[Ulexus]

It being mostly decoding load, I would definitely trim the subscription scopes, yes.
Right, ChannelVarset is the event you want.

I'm curious, though, are you actually needing something in a different goroutine or program to wait for something else to set the variable, or are you using the ChannelVarset as a confirmation of success? channel.SetVar() does provide (functional) failure indication (which is, admittedly, not universal amongst Asterisk's ARI routines).

[mtryfoss]

I guess I was a bit unclear. I do not need a specific confirmation in another goroutine.

I just wondered about the SetVariable()-function.
Is the ChannelVarset-event used to determine success or not?
If not, I cannot currently see any case where I actually need to get at notification every time a variable is changed.

I already use a heavily modified version of Asterisk, so those events could also be removed to possible reduce some load if changing subscriptions do not work.

[Ulexus]

No, you do not need to watch for the event to confirm success. Asterisk provides confirmation to the underlying REST call, which means we set the error if it fails.

The event is useful when you have one thing seeing a variable and another unrelated thing looking for a change.

[mtryfoss]

Ah, thank you!

The confirmation from the REST call drowned in all the other data.
I then assume this is such a feedback from proxy to NATS/client:

PUB _INBOX.ZAbjZi4QmaQzzIkwCcLsWF.QAh7Wfs3 12.
{"error":""}.

[mtryfoss]

..added a simple "return" in the beginning of ast_channel_publish_varset(). Reduced a lot of traffic in my case.

Will first try running an adjusted subscription during higher load tomorrow and see how that works. Else we could probably also add some sort of of filter in ari-proxy to achieve the same effect as modifying Asterisk.

[Ulexus]

That's it, yes (assuming that it is the response to a SetVar request, anyway).

Are you using a different client or reading the NATS data directly? If you are using the Go client in this repo, you shouldn't be needing to read the NATS data; it's interpreted by the client and returned as a nil error.

[mtryfoss]

I was just ngrep'ing to have a better understanding of how the communication between proxy and client works.

A normal call will set around 10 variables. Combined with all the native stuff Asterisk set during a call setup, that means a lot of events to be handled in total when call volumes go up.

I'm just thinking loud..
500 concurrent calls. Each means at least two call-legs. They have each one subscription. Total of 1000 subscriptions. Between NATS and the Go-client that would be something like 10-15000 events being published from NATS to Go for every new call. Combine that with me decoding all of them :)