Add req_header_bytes metric to h2

Author: mtrudel

lib/bandit/http2/adapter.ex

@@ -27,7 +27,7 @@ defmodule Bandit.HTTP2.Adapter do
           opts: keyword()
         }
 
-  def init(stream, method, headers, owner, opts) do
+  def init(stream, method, headers, owner, metrics, opts) do
     content_encoding =
       Bandit.Compression.negotiate_content_encoding(
         Bandit.Headers.get_header(headers, "accept-encoding"),
@@ -40,7 +40,7 @@ defmodule Bandit.HTTP2.Adapter do
       owner_pid: owner,
       opts: opts,
       content_encoding: content_encoding,
-      metrics: %{req_header_end_time: Bandit.Telemetry.monotonic_time()}
+      metrics: Map.put(metrics, :req_header_end_time, Bandit.Telemetry.monotonic_time())
     }
   end
 

lib/bandit/http2/connection.ex

@@ -81,7 +81,7 @@ defmodule Bandit.HTTP2.Connection do
 
     streams =
       with_stream(connection, 1, fn stream ->
-        Bandit.HTTP2.Stream.deliver_headers(stream, headers, false)
+        Bandit.HTTP2.Stream.deliver_headers(stream, headers, 0, false)
         Bandit.HTTP2.Stream.deliver_data(stream, data, true)
       end)
 
@@ -180,7 +180,8 @@ defmodule Bandit.HTTP2.Connection do
       {:ok, headers, recv_hpack_state} ->
         streams =
           with_stream(connection, frame.stream_id, fn stream ->
-            Bandit.HTTP2.Stream.deliver_headers(stream, headers, frame.end_stream)
+            frame_size = byte_size(frame.fragment)
+            Bandit.HTTP2.Stream.deliver_headers(stream, headers, frame_size, frame.end_stream)
           end)
 
         %{connection | recv_hpack_state: recv_hpack_state, streams: streams}

lib/bandit/http2/stream.ex

@@ -87,9 +87,12 @@ defmodule Bandit.HTTP2.Stream do
   # These functions are intended to be called by the connection process which contains this
   # stream. All of these start with `deliver_`
 
-  @spec deliver_headers(stream_handle(), Plug.Conn.headers(), boolean()) :: term()
-  def deliver_headers(:closed, _headers, _end_stream), do: :ok
-  def deliver_headers(pid, headers, end_stream), do: send(pid, {:headers, headers, end_stream})
+  @spec deliver_headers(stream_handle(), Plug.Conn.headers(), non_neg_integer(), boolean()) ::
+          term()
+  def deliver_headers(:closed, _headers, _frame_size, _end_stream), do: :ok
+
+  def deliver_headers(pid, headers, frame_size, end_stream),
+    do: send(pid, {:headers, headers, frame_size, end_stream})
 
   @spec deliver_data(stream_handle(), iodata(), boolean()) :: term()
   def deliver_data(:closed, _data, _end_stream), do: :ok
@@ -107,7 +110,7 @@ defmodule Bandit.HTTP2.Stream do
 
   def read_headers(%__MODULE__{state: :idle} = stream) do
     case do_recv(stream, stream.read_timeout) do
-      {:headers, headers, stream} ->
+      {:headers, headers, frame_size, stream} ->
         method = Bandit.Headers.get_header(headers, ":method")
         request_target = build_request_target!(headers)
 
@@ -123,7 +126,7 @@ defmodule Bandit.HTTP2.Stream do
           content_length = get_content_length!(headers)
           headers = combine_cookie_crumbs(headers)
           stream = %{stream | bytes_remaining: content_length}
-          {:ok, method, request_target, headers, stream}
+          {:ok, method, request_target, headers, %{req_header_bytes: frame_size}, stream}
         rescue
           exception ->
             reraise %{exception | method: method, request_target: request_target}, __STACKTRACE__
@@ -244,7 +247,7 @@ defmodule Bandit.HTTP2.Stream do
   defp do_read_data(%__MODULE__{state: state} = stream, max_bytes, timeout, acc)
        when state in [:open, :local_closed] do
     case do_recv(stream, timeout) do
-      {:headers, trailers, stream} ->
+      {:headers, trailers, _frame_size, stream} ->
         no_pseudo_headers!(trailers)
         Logger.warning("Ignoring trailers #{inspect(trailers)}")
         do_read_data(stream, max_bytes, timeout, acc)
@@ -278,8 +281,9 @@ defmodule Bandit.HTTP2.Stream do
 
   defp do_recv(%__MODULE__{state: :idle} = stream, timeout) do
     receive do
-      {:headers, headers, end_stream} ->
-        {:headers, headers, stream |> do_recv_headers() |> do_recv_end_stream(end_stream)}
+      {:headers, headers, frame_size, end_stream} ->
+        {:headers, headers, frame_size,
+         stream |> do_recv_headers() |> do_recv_end_stream(end_stream)}
 
       {:data, _data, _end_stream} ->
         connection_error!("Received DATA in idle state")
@@ -297,8 +301,9 @@ defmodule Bandit.HTTP2.Stream do
   defp do_recv(%__MODULE__{state: state} = stream, timeout)
        when state in [:open, :local_closed] do
     receive do
-      {:headers, headers, end_stream} ->
-        {:headers, headers, stream |> do_recv_headers() |> do_recv_end_stream(end_stream)}
+      {:headers, headers, frame_size, end_stream} ->
+        {:headers, headers, frame_size,
+         stream |> do_recv_headers() |> do_recv_end_stream(end_stream)}
 
       {:data, data, end_stream} ->
         {:data, data, stream |> do_recv_data(data) |> do_recv_end_stream(end_stream)}
@@ -315,7 +320,7 @@ defmodule Bandit.HTTP2.Stream do
 
   defp do_recv(%__MODULE__{state: :remote_closed} = stream, timeout) do
     receive do
-      {:headers, _headers, _end_stream} ->
+      {:headers, _headers, _frame_size, _end_stream} ->
         do_stream_closed_error!("Received HEADERS in remote_closed state")
 
       {:data, _data, _end_stream} ->
@@ -333,7 +338,7 @@ defmodule Bandit.HTTP2.Stream do
 
   defp do_recv(%__MODULE__{state: :closed} = stream, timeout) do
     receive do
-      {:headers, _headers, _end_stream} -> stream
+      {:headers, _headers, _frame_size, _end_stream} -> stream
       {:data, _data, _end_stream} -> stream
       {:send_window_update, _delta} -> stream
       {:rst_stream, _error_code} -> stream
@@ -470,7 +475,7 @@ defmodule Bandit.HTTP2.Stream do
 
   def ensure_completed(%__MODULE__{state: :local_closed} = stream) do
     receive do
-      {:headers, _headers, true} -> do_recv_end_stream(stream, true)
+      {:headers, _headers, _frame_size, true} -> do_recv_end_stream(stream, true)
       {:data, _data, true} -> do_recv_end_stream(stream, true)
     after
       # RFC9113§8.1 - hint the client to stop sending data

lib/bandit/http2/stream_process.ex

@@ -34,12 +34,12 @@ defmodule Bandit.HTTP2.StreamProcess do
 
   @impl GenServer
   def handle_continue(:start_stream, state) do
-    {:ok, method, request_target, headers, stream} =
+    {:ok, method, request_target, headers, header_metrics, stream} =
       Bandit.HTTP2.Stream.read_headers(state.stream)
 
     adapter =
       {Bandit.HTTP2.Adapter,
-       Bandit.HTTP2.Adapter.init(stream, method, headers, self(), state.opts)}
+       Bandit.HTTP2.Adapter.init(stream, method, headers, self(), header_metrics, state.opts)}
 
     transport_info = state.stream.transport_info
 

lib/bandit/telemetry.ex

@@ -38,7 +38,8 @@ defmodule Bandit.Telemetry do
       * `req_line_bytes`: The length of the request line, in octets. Includes all line breaks.
         Not included for HTTP/2 requests
       * `req_header_bytes`: The length of the request headers, in octets. Includes all line
-        breaks. Not included for HTTP/2 requests
+        breaks. For HTTP/2 requests, this is the number of octets in the compressed version of the
+        headers (ie: as sent on the wire)
       * `req_body_bytes`: The length of the request body, in octets
       * `resp_start_time`: The time that the response started, in `:native` units
       * `resp_end_time`: The time that the response completed, in `:native` units

test/bandit/http2/plug_test.exs

@@ -685,6 +685,7 @@ defmodule HTTP2PlugTest do
                 %{
                   monotonic_time: integer(),
                   duration: integer(),
+                  req_header_bytes: 43,
                   req_header_end_time: integer(),
                   resp_body_bytes: 0,
                   resp_start_time: integer(),
@@ -715,6 +716,7 @@ defmodule HTTP2PlugTest do
                 %{
                   monotonic_time: integer(),
                   duration: integer(),
+                  req_header_bytes: 47,
                   req_header_end_time: integer(),
                   req_body_start_time: integer(),
                   req_body_end_time: integer(),
@@ -752,6 +754,7 @@ defmodule HTTP2PlugTest do
                 %{
                   monotonic_time: integer(),
                   duration: integer(),
+                  req_header_bytes: 47,
                   req_header_end_time: integer(),
                   req_body_start_time: integer(),
                   req_body_end_time: integer(),
@@ -789,6 +792,7 @@ defmodule HTTP2PlugTest do
                 %{
                   monotonic_time: integer(),
                   duration: integer(),
+                  req_header_bytes: 54,
                   req_header_end_time: integer(),
                   req_body_start_time: integer(),
                   req_body_end_time: integer(),
@@ -823,6 +827,7 @@ defmodule HTTP2PlugTest do
                 %{
                   monotonic_time: integer(),
                   duration: integer(),
+                  req_header_bytes: 45,
                   req_header_end_time: integer(),
                   resp_body_bytes: 4,
                   resp_start_time: integer(),
@@ -852,6 +857,7 @@ defmodule HTTP2PlugTest do
                 %{
                   monotonic_time: integer(),
                   duration: integer(),
+                  req_header_bytes: 49,
                   req_header_end_time: integer(),
                   resp_body_bytes: 6,
                   resp_start_time: integer(),