How can I get the response time of a HTTP request in elixir?

I need this time too. I was thinking to measure it by system timer probably will do the job.

I tend to do something like

{microseconds, result} = :timer.tc(fn -> do_the_request(...) end)
milliseconds = System.convert_time_unit(microseconds, :microseconds, :millisecond)

I do this

start_ms = System.monotonic_time(:milliseconds)

# do the request and receive response
    
end_ms = System.monotonic_time(:milliseconds)
diff = end_ms - start_ms

I’ve already tried with timer.tc. It’s not actual response time but function execution time. I thought there won’t be huge gap between those two but it was really quite different

If I recall correctly, Phoenix 1.4 is partially focused on collecting/reporting metrics: https://www.youtube.com/watch?v=pfFpIjFOL-I

Although if you’re not using Phoenix you won’t benefit directly, but maybe you can see what sort of approach it takes to metrics.

Agreed. There can be quite a bit of difference here, especially when the HTTP client pool is overloaded. The function execution time can be large, even if the response time is faster.

Hackney though has metrics. (See Metrics on GitHub - benoitc/hackney: simple HTTP client in Erlang · GitHub). It seems like it is tracking request and response times among other things. Perhaps it is closer to what you want.

It supports two erlang metrics libraries, but you can write your own as long as you implement the correct contract for your module if folsom or exometer is not your cup of tea or hard to integrate into elixir (I have no idea here).

Yes, I am doing in Phoenix project. I’ll check the video..

I don’t know if that would work for you (I’ve seen it being used in knutin/elli), but if all of your work is done in a single process, you can put timings into the process dictionary:

defp t(key) do
  :erlang.put({:time, key}, :os.timestamp())
end

and call it in different places inside the same process

t(:start_request)
# request something
t(:done_requesting)
t(:start_parsing_body)
# parse body
t(:done_parsing_body)

and then collect the timings at some point later (you would need to be in the same process though).

Enum.flat_map(:erlang.get(), fn
  {{:time, event} = key, time} ->
    :erlang.erase(key)
    [{event, time}]
  
  _ ->
    []
end)

which would return something like

timings = [start_request: {1518, 275996, 334820}, done_requesting: {1518, 276000, 54915}]

and you can calculate diffs with :timer.now_diff/2

start_request = timings[:start_request]
done_requesting = timings[:done_requesting]

:timer.now_diff(done_requesting, start_request)
#=> 3720095 (microseconds)

You might want to read Two frequently used system calls are ~77% slower on AWS EC2 if you are on xen. I think beam uses these calls if it is compiled with --enable-gettimeofday-as-os-system-time and erl_xcomp_clock_gettime_cpu_time set to yes, but I might be wrong.

Okay. it’s worth a try.

It seems that the issue here is that the process management built into the packages makes it hard to see what is really going on with the process, and therefore using :timer is not timing what you think it is.

My question for someone who knows – Is there a way to fix this purely in elixir, or is Erlang required for http calls? And since the elixir packages are basically wrappers for the Erlang packages, I am wondering if the Elixir community is leaning more towards contributing pull requests to the elixir packages OR just using the underlying Erlang library.

I think it would be really great if somebody with experience with this could explain whats the idiomatic way to handle this problem. The elixir async model is making it hard to measure the actual http… and it seems that making http requests maybe should be part of the standard library.