Don't log connection closed exceptions as ERROR in websockets-next #40246
Conversation
This comment has been minimized.
This comment has been minimized.
There was a problem hiding this comment.
The clients can choose to close at any time, so it does not make sense to fill up logs with closed connection messages
I can't say that I agree with this proposal.
When a client closed a connection then the callback should not be called at all. If it is then it should only happen infrequently (when the connection is closed during processing or something like that). When exactly do you observe the logs filled with "closed connection" messages?
Also a user can define a global error handler to filter out these exceptions.
...sts/opentelemetry-scheduler/src/main/java/io/quarkus/it/opentelemetry/scheduler/Counter.java
Outdated
Show resolved
Hide resolved
| if (message == null) { | ||
| return false; | ||
| } | ||
| return message.contains("WebSocket is closed"); |
There was a problem hiding this comment.
Hm, this detection mechanism is too brittle. I know that there's no specific exception but this is not good at all.
There was a problem hiding this comment.
The exception is a NoStackTraceException so there is nothing to go by.
I do agree it's brittle, but I don't see any alternative and having useless ERROR log entries is worse IMHO.
There was a problem hiding this comment.
The exception is a
NoStackTraceExceptionso there is nothing to go by.
Yes, this is something we could report in Vertx maybe? One thing we could do is to also test the connection with WebSocketConnection.isClosed(), i.e. connections.isClosed() && message.contains("WebSocket is closed") .
I do agree it's brittle, but I don't see any alternative and having useless ERROR log entries is worse IMHO.
Well, the question is whether it's truly useless (some users might be interested in this) and as I pointed out the other question is how often does it actually happen?
We could also make this configurable, i.e. something like quarkus.websockets-next.server.log-closed-connection-errors with default value false 🤷.
There was a problem hiding this comment.
Well, the question is whether it's truly useless (some users might be interested in this) and as I pointed out the other question is how often does it actually happen?
I easily made it happen in tests.
I also don't see why developers would need this in their logs, but let's see what @cescoffier thinks as well
There was a problem hiding this comment.
I also don't see why developers would need this in their logs, but let's see what @cescoffier thinks as well
It's a signal that something went wrong on the server 🤷. Maybe we could use WARNING and no stack trace instead?
There was a problem hiding this comment.
FWIW, I agree with @geoand that we should avoid logging connection errors that can be easily initiated by the client. I would even say that it could be seen as a potential security issue if you can easily fill the logs with stacktraces by disconnecting clients.
There was a problem hiding this comment.
even say that it could be seen as a potential security issue if you can easily fill the logs with stacktraces by disconnecting clients
Definitely.
Also, I am fairly sure we don't log these errors (or warnings) in our REST stack when the connection goes away before the response can be written
There was a problem hiding this comment.
that we should avoid logging connection errors that can be easily initiated by the client
Like I mentioned above this should only happen infrequently - when the connection is closed during processing of a message or something like that.
I would even say that it could be seen as a potential security issue if you can easily fill the logs with stacktraces by disconnecting clients.
I disagree. In that case, any server error would meet these conditions 🤔.
But like I mentioned in #40246 (comment) we should probably log a WARNING instead.
The only problem I can see is that the test relies on an exception message, which is super-brittle, may lead to false positives etc. We should at least combine (exception instanceof VertxException) && connections.isClosed() && message.contains("WebSocket is closed")
PS. I'm in the middle of a huge refactoring due to WebSocket client impl and I'm not going to merge any websocket-next PRs until the refactoring is finished 🤷.
There was a problem hiding this comment.
I disagree. In that case, any server error would meet these conditions 🤔.
The differentiator is when the user can trigger at will. That is why in Quarkus REST we don't log anything by default.
There was a problem hiding this comment.
I disagree. In that case, any server error would meet these conditions
It actually really depends on the conditions.
See for instance: GHSA-89h3-g746-xmwq
The only problem I can see is that the test relies on an exception message, which is super-brittle
That I agree. I would advise that we live with it (with your suggestion included if it works) until something in Vert.x allows us to do better (but we would need to create an issue there)?
geoand
force-pushed
the
websockets-logging
branch
from
62cd218 to
3634485
Compare
This comment has been minimized.
This comment has been minimized.
|
PR rebased |
This comment has been minimized.
This comment has been minimized.
| } | ||
|
|
||
| private static boolean isWebSocketIsClosedFailure(Throwable throwable) { | ||
| if (throwable == null) { |
There was a problem hiding this comment.
Could we add a check that WebSocketConnectionBase#isClosed() returns true?
I wonder if we should create a Vertx issue to introduce ConnectionClosedException or something like that...
There was a problem hiding this comment.
Could we add a check that WebSocketConnectionBase#isClosed() returns true?
Done
I wonder if we should create a Vertx issue to introduce ConnectionClosedException or something like that.
@vietj would you be willing to have that in Vertx?
The clients can choose to close at any time, so it does not make sense to fill up logs with closed connection messages
Status for workflow
|
|
If we want this in 3.10, we will need a specific backport as this class has been refactored in 3.11 AFAICS. |
|
I can do that on Monday |
The clients can choose to close at any time, so it does not make sense to fill up logs with closed connection messages