Use middleware to log time it takes client to receive response

I’m trying to understand how to use HTTP.jl’s middleware to log the amount of time between two distinct events:

  1. The server started sending the response
  2. The client received it

The following MWE doesn’t accomplish this, but might serve as a good starting point:

using HTTP, Random

const times = UInt64[]

function get_durations(times)
    calculating, sending = round.(diff(times) ./ 10^9, digits = 4)
    @info "durations:" calculating sending
    empty!(times)
end

function log_time(handler)
    return function(req)
        ret = handler(req)
        push!(times, time_ns()) # log time to send data?
        get_durations(times)
        return ret
    end
end

function handler(req)
    push!(times, time_ns()) # log starting time
    data = randstring(1_000_000)
    push!(times, time_ns()) # log time to calculate data
    return HTTP.Response(200, data)
end

HTTP.serve(log_time(handler))

Maybe this is simply impossible…?

Generally you can’t know this during request handling. There may be intervening servers, such as reverse proxies. If you control the client, maybe have the client send back a timestamp after receiving the response.

1 Like

Yeah, I agree. We could potentially add an “eventing system” to HTTP.jl on both client and server side so you could hook into various checkpoints, but even then, you would need to even both client and server to really get what you’re after here.

@christopher-dG came up with a really good suggestion, and it’s to use a modified streamhandler (original copied from HTTP.jl/Handlers.jl at master · JuliaWeb/HTTP.jl · GitHub), for example:

function streamhandler_with_timings(handler)
    return function(stream::HTTP.Stream)
        request::HTTP.Request = stream.message
        request.body = read(stream)
        closeread(stream)
        request.response::HTTP.Response = handler(request)
        request.response.request = request
        @time begin
            startwrite(stream)
            write(stream, request.response.body)
        end # done sending
        return
    end
end

What do you think about that?

This doesn’t address the issue raised above. The client doesn’t necessarily receive the response when the server has finished writing. It depends on your use case and client/server configuration whether it is good enough.