HTTP level request response Logging

[shunsukew]

I would like to do RPC logging at the HTTP level to emit a single line per request/response. The desired log format would be similar to that used by other proxy/gateway solutions, such as Kong has. An example log format is as follows:

{
    "protocol": "http", // or "ws"
    "request": {
        "headers": {},
        "body": {},
        ...
    },
    "response": {
        "body": {},
        ...
    },
    "started_at": "",
    "elapsed": ""
}

The purpose of this logging is to inspect and aggregate logs for subsequent use, including HTTP-level information such as status codes, request origins, and so forth. This can be achieved by adding logging at this location for HTTP and this location for WebSocket.

Would it be possible to make this logging feature optionally available in jsonrpsee? I understand that this may not be interesting for most use cases, and I am open to maintaining a fork of jsonrpsee to implement this feature for our usecase.

---

Cannot implement at tower http middleware because

• for ws, only connection upgrade request is visible there in my understanding.
• this introduces another request body recovery from data frames, which is additional overhead.

Cannot implement at rpc moddleware because

• cannot access http level information such as response http status.

[niklasad1]

I think most of what you want is possible but you need to read the body of request/response which may be a little overhead.

for ws, only connection upgrade request is visible there in my understanding.

Simply you use utilize jsonrpsee as tower service and then you could do manage that yourself:

    let svc = tower::service_fn(move |req: hyper::Request<hyper::body::Incoming>| {
        let is_websocket = jsonrpsee::server::ws::is_upgrade_request(&req);
        let transport_label = if is_websocket { "ws" } else { "http" };

        // extract stuff that you are interested here from the request here

        async move {
            if is_websocket {
                let on_disconnect = svc.on_session_closed();

                // Spawn a task to handle when the connection is closed.
                tokio::spawn(async move {
                    let now = std::time::Instant::now();
                    on_disconnect.await;
                    tracing::debug!("protocol: ws, duration: {now}")
                });
            }

            let rp = svc.call(req).await;

            // extract stuff that you are interested here from the response here
            tracing::debug!("protocol: {transport_label}, ...")
        }
    });

Cannot implement at rpc moddleware because cannot access http level information such as response http status.

You can write custom RPC middleware layer that extract that stuff from the http request itself to be accessible for the rpc middleware, have look at this example

I think these APIs should be sufficiently flexible for anyone to implement what you want

[shunsukew]

I think most of what you want is possible but you need to read the body of request/response which may be a little overhead.

Yes, in case we read the body from hyper::body::Incoming at somewhere other than call_with_service fn. If possible, this step should be done only once to avoid reading twice.

Simply you use utilize jsonrpsee as tower service and then you could do manage that yourself:

In above code snippet, we can see connection upgrade req and rp, but cannot see websocket messages inside an established connection. ws message is recovered here in ws background task for the first time. so rpc method calls sent as ws message from client side cannot be detected at tower service (is not hyper::Request<hyper::body::Incoming>) I think. (please correct me if I'm wrong)

You can write custom RPC middleware layer that extract that stuff from the http request itself to be accessible for the rpc middleware, have look at this example

Thank you! but what about http response status code? status code will be decided after exiting from rpc middlewares.