How to access response time?

Hey, I’m wanting to log response time to an external service, in an exact format that i choose. How do I access the full response time? (I disabled it in logging instead as I’m dealing with high request volume and am trying to improve performance)

Whatever you will do it will have almost exactly the same impact as logging. However what you want is already there available as instrumentation.

How do I use this in a controller to get the timeout?

You’ll need to wrap the call to the external service to grab the timing. You can use :timer.tc/1 to wrap a function and get a {microsecond, result} tuple back. After that it is up to you to log it out manually with Logger.

I already do that to some extent but I wanted the actual response time as exact as possible, without overhead. So i was hoping i could access the same response time that phoenix logger uses when it says “responded in 232ms”

:timer.tc/1 returns microseconds. Even a local connection over the network is in the order of milliseconds. Have you found that microseconds aren’t accurate enough?

1 Like

What I mean is that if I time inside the controller I’m not getting all the overhead of phoenix, im just getting inside the controller.

1 Like

Are you proxying to Phoenix using an application like Nginx? You could capture the time(s) there.

No proxy, just phoenix

Create a plug that will live at the end of your Endpoint or (maybe) see if you can do something with custom dispatchers ( Phoenix.Endpoint.CowboyAdapter / Phoenix.Endpoint.Cowboy2Adapter ).

Plugs at the end of the endpoint don’t work, since whichever plug sends the response also halts the pipeline, which prevents further plugs from running.

To run something before plug is sent, use https://hexdocs.pm/plug/Plug.Conn.html#register_before_send/2

You can see it at work with the Plug Logger https://github.com/elixir-plug/plug/blob/v1.7.1/lib/plug/logger.ex#L33

1 Like

I didn’t imagine the plug would be written to block for longer then the time it takes to spawn a process where the process would send the data to the third party. If its not linked or awaited on then the plug should continue on and return. Correct me if I am wrong, also just spit balling ideas.

Plug.Conn.register_before_send/2 does seem like a clean way to accomplish the above without an extra plug / process.

By “block” I mean “literally prevents the function from being called”. If you have:

plug A
plug B
plug C

and B sends the response, C will never be run at all. Concretely this prevents strategies like:

plug Parsers
plug MyApp.Router
plug MetricsReporter
1 Like

ahhh ok I follow now, thanks. Makes sense that C never gets executed when B actually sends the response.

Dumb question but where do I add that? I havent really ever used phoenix before, do I need to create a new plug or something?

Note: I was actually going to push the stats using a message pass in the actual controller. I’m doing it there because theres a lot of other stats im collecting about various things. So I just would like to access it in the controller if possible

How could the response time be available in the controller when the response hasn’t happened yet? This doesn’t seem like something the controller should know or care about. It also won’t help if some plug higher up the stack (like auth) prevents the controller from running.

You’re right that was a mega dumb question. Ok I would be fine not doing it in the controller then. The action I want to do instead of logging is a cast to something else (a stats logger) so i suspect it wont really block.