micrometer icon indicating copy to clipboard operation
micrometer copied to clipboard

Jetty Connector Metrics are only reported onClosed

Open kelunik opened this issue 2 years ago • 4 comments

Describe the bug

io.micrometer.core.instrument.binder.jetty.JettyConnectionMetrics reports metrics only in onClosed. Thus, connections receiving lots of traffic / messages but that are kept open, will never be visible in the metrics, then create a high peak at closure.

Environment

  • Micrometer version: 1.10.6
  • Micrometer registry: Simple + Elastic APM Agent
  • OS: Linux
  • Java version: 17.0.7

To Reproduce

Server server = new Server(createThreadPool());
ServerConnector connector = new ServerConnector(server, 2, -1, tls, alpn, h2);
connector.addBean(new JettyConnectionMetrics(MetricsRegistry.register(), connector, List.of()));
connector.setPort(1234);
server.addConnector(connector);

Keep the connection in the client open (e.g. OkHttp and send a request every minute - default idle time is 5 minutes).

Expected behavior

Traffic being visible in the reported metrics.

kelunik avatar Jun 01 '23 14:06 kelunik

So what would be the expected outcome? Would you want the metrics to be available as gauges?

marcingrzejszczak avatar Dec 27 '23 15:12 marcingrzejszczak

No, counters are fine, but metrics should be recorded when bytes are sent / received instead of on connection closure.

kelunik avatar Dec 28 '23 19:12 kelunik

I see, so instead of doing a listener on the connection, most likely we should be using the NetworkTrafficListener and use the incoming and outgoing methods?

public interface NetworkTrafficListener
{
    /**
     * <p>Callback method invoked when a connection from a remote client has been accepted.</p>
     * <p>The {@code socket} parameter can be used to extract socket address information of
     * the remote client.</p>
     *
     * @param socket the socket associated with the remote client
     */
    default void opened(Socket socket)
    {
    }

    /**
     * <p>Callback method invoked when bytes sent by a remote client arrived on the server.</p>
     *
     * @param socket the socket associated with the remote client
     * @param bytes the read-only buffer containing the incoming bytes
     */
    default void incoming(Socket socket, ByteBuffer bytes)
    {
    }

    /**
     * <p>Callback method invoked when bytes are sent to a remote client from the server.</p>
     * <p>This method is invoked after the bytes have been actually written to the remote client.</p>
     *
     * @param socket the socket associated with the remote client
     * @param bytes the read-only buffer containing the outgoing bytes
     */
    default void outgoing(Socket socket, ByteBuffer bytes)
    {
    }

marcingrzejszczak avatar Dec 29 '23 09:12 marcingrzejszczak

I'm no expert in Jetty, but after changing the JettyConnectionMetrics to also implement NetworkTrafficListener, and by changing its contract to call this

@Override
    public void incoming(Socket socket, ByteBuffer bytes) {
        bytesIn.record(bytes.limit());
    }

    @Override
    public void outgoing(Socket socket, ByteBuffer bytes) {
        bytesOut.record(bytes.limit());
    }

I can make the tests pass on the server side (I return the same amount of bytes), but I have a difference in bytes between what we are returning when the connection gets closed vs when the outgoing bytes get reported through the NetworkTrafficListener for the client side.

In case of JettyConnectionMetricsTest with metrics done on the connection close there it turns out that there are 2 connections being closed. One with 166 bytes getting dumped and the other with 618 bytes - together 784 bytes.

With the NTL changes we report only the 618 bytes (166 bytes are missing in comparison to the bytes before my change). Those are combined from 174 bytes and 442 bytes that are being gathered by 2 calls to the outgoing method.

Are there any Jetty experts that can explain this? Maybe I'm misusing the ByteBuffer. You can check the draft PR here

marcingrzejszczak avatar Dec 29 '23 11:12 marcingrzejszczak