xroot access log file fails to log incomplete operations

[paulmillar]

The access log file for the Xrootd is implemented as the class org.dcache.xrootd.plugins.AccessLogHandler.

From manual inspection of the code, there appears to be a limitation in the current implementation.

Most xroot commands will result in the xrootd door sending a (dCache internal) message to some dCache component. The door then waits for the response from this message and then sends the client the appropriate xroot response.

The current behaviour of the AccessLogHandler class involves logging the request when the xrootd door sends the response to the client. This is because the access log entry should include information about both the request and the response; e.g., whether the request was successful.

In addition, the AccessLogHandler records when a client disconnects (channel becomes inactive) as an org.dcache.xrootd.connection.end event.

If the channel becomes inactive after the client as sent an xroot request, triggering the xrootd door sending a dCache internal message, but before the door receives the (dCache internal) response message then the door will not send a response to the client. Without this response, the in-flight request is not logged.

According to this info, the SLAC xrootd client by default waits 60 seconds for a response. In an overload scenario, it is possible that responses take too long and the client simply disconnects. In such cases, the xrootd request may be successful, but there is no record of the client request.

Speculating, but this issue may be the reason why xrootd client activity is not being logged in #7613.

A related (but separate!) issue involves the xrootd door degrading gracefully under overload conditions; for example, using xroot protocol's support (kXR_wait) to indicate the request is still being processed, which would extend the client's timeout.