From 5b1cbf030695f91929ab361ba96c5d12b95ddd3c Mon Sep 17 00:00:00 2001 From: Rossen Stoyanchev Date: Wed, 24 Sep 2014 09:43:16 -0400 Subject: [PATCH] Log WebSocket connection issues at DEBUG level WebSocket clients going away is an expected and common occurance. Logging at ERROR level on failure to close a connection or on failures to write data to a WebSocket sessions has a high potential for false positives with very little to do. This change lowers the log level for a number of log messages that fit this category. This should be helped by the effort already spent for 4.1 to ensure logging at DEBUG level doesn't produce excessive amounts of logging. Issue: SPR-12155 --- .../handler/ExceptionWebSocketHandlerDecorator.java | 6 ++++-- .../handler/LoggingWebSocketHandlerDecorator.java | 4 ++-- .../socket/messaging/StompSubProtocolHandler.java | 8 +++++--- .../messaging/SubProtocolWebSocketHandler.java | 9 ++++++--- .../transport/TransportHandlingSockJsService.java | 5 +++-- .../transport/session/AbstractHttpSockJsSession.java | 3 ++- .../transport/session/AbstractSockJsSession.java | 12 +++++++----- 7 files changed, 29 insertions(+), 18 deletions(-) diff --git a/spring-websocket/src/main/java/org/springframework/web/socket/handler/ExceptionWebSocketHandlerDecorator.java b/spring-websocket/src/main/java/org/springframework/web/socket/handler/ExceptionWebSocketHandlerDecorator.java index 2b1345ff58f..aa7e7b0cf06 100644 --- a/spring-websocket/src/main/java/org/springframework/web/socket/handler/ExceptionWebSocketHandlerDecorator.java +++ b/spring-websocket/src/main/java/org/springframework/web/socket/handler/ExceptionWebSocketHandlerDecorator.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2013 the original author or authors. + * Copyright 2002-2014 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -52,7 +52,9 @@ public class ExceptionWebSocketHandlerDecorator extends WebSocketHandlerDecorato } public static void tryCloseWithError(WebSocketSession session, Throwable exception, Log logger) { - logger.error("Closing due to exception for " + session, exception); + if (logger.isDebugEnabled()) { + logger.debug("Closing due to exception for " + session, exception); + } if (session.isOpen()) { try { session.close(CloseStatus.SERVER_ERROR); diff --git a/spring-websocket/src/main/java/org/springframework/web/socket/handler/LoggingWebSocketHandlerDecorator.java b/spring-websocket/src/main/java/org/springframework/web/socket/handler/LoggingWebSocketHandlerDecorator.java index d4645aaeeab..b34072e4af1 100644 --- a/spring-websocket/src/main/java/org/springframework/web/socket/handler/LoggingWebSocketHandlerDecorator.java +++ b/spring-websocket/src/main/java/org/springframework/web/socket/handler/LoggingWebSocketHandlerDecorator.java @@ -57,8 +57,8 @@ public class LoggingWebSocketHandlerDecorator extends WebSocketHandlerDecorator @Override public void handleTransportError(WebSocketSession session, Throwable exception) throws Exception { - if (logger.isErrorEnabled()) { - logger.error("Transport error in " + session, exception); + if (logger.isDebugEnabled()) { + logger.debug("Transport error in " + session, exception); } super.handleTransportError(session, exception); } diff --git a/spring-websocket/src/main/java/org/springframework/web/socket/messaging/StompSubProtocolHandler.java b/spring-websocket/src/main/java/org/springframework/web/socket/messaging/StompSubProtocolHandler.java index dcbc8b837c1..e50637e0f01 100644 --- a/spring-websocket/src/main/java/org/springframework/web/socket/messaging/StompSubProtocolHandler.java +++ b/spring-websocket/src/main/java/org/springframework/web/socket/messaging/StompSubProtocolHandler.java @@ -255,7 +255,7 @@ public class StompSubProtocolHandler implements SubProtocolHandler, ApplicationE } } catch (Throwable ex) { - logger.error("Failed to send STOMP message from client to application MessageChannel" + + logger.error("Failed to send client message to application via MessageChannel" + " in session " + session.getId() + ". Sending STOMP ERROR to client.", ex); sendErrorMessage(session, ex); @@ -280,7 +280,8 @@ public class StompSubProtocolHandler implements SubProtocolHandler, ApplicationE session.sendMessage(new TextMessage(bytes)); } catch (Throwable ex) { - logger.error("Failed to send STOMP ERROR to client.", ex); + // Could be part of normal workflow (e.g. browser tab closed) + logger.debug("Failed to send STOMP ERROR to client.", ex); } } @@ -330,7 +331,8 @@ public class StompSubProtocolHandler implements SubProtocolHandler, ApplicationE throw ex; } catch (Throwable ex) { - logger.error("Failed to send WebSocket message to client in session " + session.getId() + ".", ex); + // Could be part of normal workflow (e.g. browser tab closed) + logger.debug("Failed to send WebSocket message to client in session " + session.getId() + ".", ex); command = StompCommand.ERROR; } finally { diff --git a/spring-websocket/src/main/java/org/springframework/web/socket/messaging/SubProtocolWebSocketHandler.java b/spring-websocket/src/main/java/org/springframework/web/socket/messaging/SubProtocolWebSocketHandler.java index d0e642a01e5..042909abeb3 100644 --- a/spring-websocket/src/main/java/org/springframework/web/socket/messaging/SubProtocolWebSocketHandler.java +++ b/spring-websocket/src/main/java/org/springframework/web/socket/messaging/SubProtocolWebSocketHandler.java @@ -333,17 +333,20 @@ public class SubProtocolWebSocketHandler implements WebSocketHandler, } catch (SessionLimitExceededException ex) { try { - logger.error("Terminating '" + session + "'", ex); + if (logger.isDebugEnabled()) { + logger.debug("Terminating '" + session + "'", ex); + } this.stats.incrementLimitExceededCount(); clearSession(session, ex.getStatus()); // clear first, session may be unresponsive session.close(ex.getStatus()); } catch (Exception secondException) { - logger.error("Failure while closing session " + sessionId + ".", secondException); + logger.debug("Failure while closing session " + sessionId + ".", secondException); } } catch (Exception e) { - logger.error("Failed to send message to client in " + session + ": " + message, e); + // Could be part of normal workflow (e.g. browser tab closed) + logger.debug("Failed to send message to client in " + session + ": " + message, e); } } diff --git a/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/TransportHandlingSockJsService.java b/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/TransportHandlingSockJsService.java index 3ebcd55e000..d6212ebe62d 100644 --- a/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/TransportHandlingSockJsService.java +++ b/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/TransportHandlingSockJsService.java @@ -178,7 +178,7 @@ public class TransportHandlingSockJsService extends AbstractSockJsService implem catch (Throwable ex) { failure = new HandshakeFailureException("Uncaught failure for request " + request.getURI(), ex); } - finally { + finally { if (failure != null) { chain.applyAfterHandshake(request, response, failure); throw failure; @@ -303,7 +303,8 @@ public class TransportHandlingSockJsService extends AbstractSockJsService implem } } catch (Throwable ex) { - logger.error("Failed to close " + session, ex); + // Could be part of normal workflow (e.g. browser tab closed) + logger.debug("Failed to close " + session, ex); } } if (logger.isDebugEnabled() && !removedSessionIds.isEmpty()) { diff --git a/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/session/AbstractHttpSockJsSession.java b/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/session/AbstractHttpSockJsSession.java index c44b7e81911..0ac0acff83e 100644 --- a/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/session/AbstractHttpSockJsSession.java +++ b/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/session/AbstractHttpSockJsSession.java @@ -323,7 +323,8 @@ public abstract class AbstractHttpSockJsSession extends AbstractSockJsSession { control.complete(); } catch (Throwable ex) { - logger.error("Failed to complete request: " + ex.getMessage()); + // Could be part of normal workflow (e.g. browser tab closed) + logger.debug("Failed to complete request: " + ex.getMessage()); } } } diff --git a/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/session/AbstractSockJsSession.java b/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/session/AbstractSockJsSession.java index eaad7590c46..5495bfdf41f 100644 --- a/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/session/AbstractSockJsSession.java +++ b/spring-websocket/src/main/java/org/springframework/web/socket/sockjs/transport/session/AbstractSockJsSession.java @@ -291,7 +291,7 @@ public abstract class AbstractSockJsSession implements SockJsSession { this.handler.afterConnectionClosed(this, status); } catch (Throwable ex) { - logger.error("Error from WebSocketHandler.afterConnectionClosed in " + this, ex); + logger.debug("Error from WebSocketHandler.afterConnectionClosed in " + this, ex); } } } @@ -307,7 +307,9 @@ public abstract class AbstractSockJsSession implements SockJsSession { * Close due to error arising from SockJS transport handling. */ public void tryCloseWithSockJsTransportError(Throwable error, CloseStatus closeStatus) { - logger.error("Closing due to transport error for " + this); + if (logger.isDebugEnabled()) { + logger.debug("Closing due to transport error for " + this); + } try { delegateError(error); } @@ -318,7 +320,7 @@ public abstract class AbstractSockJsSession implements SockJsSession { close(closeStatus); } catch (Throwable closeException) { - logger.error("Failure while closing " + this, closeException); + logger.debug("Failure while closing " + this, closeException); } } @@ -370,7 +372,7 @@ public abstract class AbstractSockJsSession implements SockJsSession { } } else { - logger.error("Terminating connection after failure to send message to client.", failure); + logger.debug("Terminating connection after failure to send message to client.", failure); } } @@ -421,7 +423,7 @@ public abstract class AbstractSockJsSession implements SockJsSession { } } catch (Throwable ex) { - logger.error("Failure while cancelling heartbeat in session " + getId(), ex); + logger.debug("Failure while cancelling heartbeat in session " + getId(), ex); } }