From 1f1bfff4f7dd32036fd9610bb82a5f45c3bb62b4 Mon Sep 17 00:00:00 2001
From: Luis Barrios <lbarriosh.public@gmail.com>
Date: Wed, 11 Jan 2017 15:33:23 +0100
Subject: [PATCH] Improve logging: - When a MQTT message is received, we should
 only log it in debug level. It is better to log the actions performed in the
 protocol processor at the info level (they are more meaningful). - Capture
 and log every exception raised while processing the message (including
 RuntimeExceptions).

---
 .../server/netty/NettyMQTTHandler.java        | 27 +++++++++----------
 1 file changed, 13 insertions(+), 14 deletions(-)

diff --git a/broker/src/main/java/io/moquette/server/netty/NettyMQTTHandler.java b/broker/src/main/java/io/moquette/server/netty/NettyMQTTHandler.java
index 1f5ca354..0e4a9854 100644
--- a/broker/src/main/java/io/moquette/server/netty/NettyMQTTHandler.java
+++ b/broker/src/main/java/io/moquette/server/netty/NettyMQTTHandler.java
@@ -23,12 +23,10 @@ import io.netty.channel.ChannelHandler.Sharable;
 import io.netty.channel.ChannelHandlerContext;
 import io.netty.channel.ChannelInboundHandlerAdapter;
 
-import io.netty.handler.codec.CorruptedFrameException;
 
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
-import java.io.IOException;
 
 /**
  *
@@ -47,7 +45,10 @@ public class NettyMQTTHandler extends ChannelInboundHandlerAdapter {
     @Override
     public void channelRead(ChannelHandlerContext ctx, Object message) {
         AbstractMessage msg = (AbstractMessage) message;
-        LOG.info("Received a message of type {}", Utils.msgType2String(msg.getMessageType()));
+        String messageType = Utils.msgType2String(msg.getMessageType());
+        if (LOG.isDebugEnabled()) {
+        	LOG.debug("Processing MQTT message. MessageType = {}.", messageType);
+        }
         try {
             switch (msg.getMessageType()) {
                 case CONNECT:
@@ -82,9 +83,11 @@ public class NettyMQTTHandler extends ChannelInboundHandlerAdapter {
                     ctx.writeAndFlush(pingResp);
                     break;
             }
-        } catch (Exception ex) {
-            LOG.error("Bad error in processing the message", ex);
-            ctx.fireExceptionCaught(ex);
+        } catch (Throwable ex) {
+			LOG.error(
+					"An unexpected exception was caught while processing MQTT message. MessageType = {}, cause = {}, errorMessage = {}.",
+					messageType, ex.getCause(), ex.getMessage());
+			ctx.fireExceptionCaught(ex);
         }
     }
     
@@ -92,6 +95,7 @@ public class NettyMQTTHandler extends ChannelInboundHandlerAdapter {
     public void channelInactive(ChannelHandlerContext ctx) throws Exception {
         String clientID = NettyUtils.clientID(ctx.channel());
         if (clientID != null && !clientID.isEmpty()) {
+			LOG.info("Notifying connection lost event. MqttClientId = {}.", clientID);
             m_processor.processConnectionLost(clientID, ctx.channel());
         }
         ctx.close();
@@ -99,14 +103,9 @@ public class NettyMQTTHandler extends ChannelInboundHandlerAdapter {
 
     @Override
     public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception {
-        if (cause instanceof CorruptedFrameException) {
-            //something goes bad with decoding
-            LOG.warn("Error decoding a packet, probably a bad formatted packet, message: " + cause.getMessage());
-        } else if (cause instanceof IOException && "Connection reset by peer".equals(cause.getMessage())) {
-            LOG.warn("Network connection closed abruptly");
-        } else {
-            LOG.error("Ugly error on networking", cause);
-        }
+		LOG.error(
+				"An unexpected exception was caught while processing MQTT message. Closing Netty channel. MqttClientId = {}, cause = {}, errorMessage = {}.",
+				NettyUtils.clientID(ctx.channel()), cause.getCause(), cause.getMessage());
         ctx.close();
     }