Improving log messages

acceptor/tcp_acceptor.go

@@ -90,7 +90,7 @@ func (a *TCPAcceptor) ListenAndServe() {
 
 	listener, err := net.Listen("tcp", a.addr)
 	if err != nil {
-		logger.Log.Fatal(err)
+		logger.Log.Fatalf("Failed to listen: %s", err.Error())
 	}
 	a.listener = listener
 	a.running = true
@@ -101,7 +101,7 @@ func (a *TCPAcceptor) ListenAndServe() {
 func (a *TCPAcceptor) ListenAndServeTLS(cert, key string) {
 	crt, err := tls.LoadX509KeyPair(cert, key)
 	if err != nil {
-		logger.Log.Fatal(err)
+		logger.Log.Fatalf("Failed to listen: %s", err.Error())
 	}
 
 	tlsCfg := &tls.Config{Certificates: []tls.Certificate{crt}}
@@ -117,7 +117,7 @@ func (a *TCPAcceptor) serve() {
 	for a.running {
 		conn, err := a.listener.Accept()
 		if err != nil {
-			logger.Log.Error(err.Error())
+			logger.Log.Errorf("Failed to accept TCP connection: %s", err.Error())
 			continue
 		}
 

acceptor/ws_acceptor.go

@@ -88,7 +88,7 @@ func (h *connHandler) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
 
 	c, err := newWSConn(conn)
 	if err != nil {
-		logger.Log.Error(err)
+		logger.Log.Errorf("Failed to create new ws connection: %s", err.Error())
 		return
 	}
 	h.connChan <- c
@@ -115,7 +115,7 @@ func (w *WSAcceptor) ListenAndServe() {
 
 	listener, err := net.Listen("tcp", w.addr)
 	if err != nil {
-		logger.Log.Fatal(err)
+		logger.Log.Fatalf("Failed to listen: %s", err.Error())
 	}
 	w.listener = listener
 
@@ -131,13 +131,13 @@ func (w *WSAcceptor) ListenAndServeTLS(cert, key string) {
 
 	crt, err := tls.LoadX509KeyPair(cert, key)
 	if err != nil {
-		logger.Log.Fatal(err)
+		logger.Log.Fatalf("Failed to load x509: %s", err.Error())
 	}
 
 	tlsCfg := &tls.Config{Certificates: []tls.Certificate{crt}}
 	listener, err := tls.Listen("tcp", w.addr, tlsCfg)
 	if err != nil {
-		logger.Log.Fatal(err)
+		logger.Log.Fatalf("Failed to listen: %s", err.Error())
 	}
 	w.listener = listener
 	w.serve(&upgrader)
@@ -156,7 +156,7 @@ func (w *WSAcceptor) serve(upgrader *websocket.Upgrader) {
 func (w *WSAcceptor) Stop() {
 	err := w.listener.Close()
 	if err != nil {
-		logger.Log.Error(err)
+		logger.Log.Errorf("Failed to stop: %s", err.Error())
 	}
 }
 

agent/agent.go

@@ -351,7 +351,7 @@ func (a *Agent) write() {
 		case data := <-a.chSend:
 			payload, err := util.SerializeOrRaw(a.serializer, data.payload)
 			if err != nil {
-				logger.Log.Error(err.Error())
+				logger.Log.Errorf("Failed to serialize response: %s", err.Error())
 				payload, err = util.GetErrorPayload(a.serializer, err)
 				if err != nil {
 					tracing.FinishSpan(data.ctx, err)
@@ -377,7 +377,7 @@ func (a *Agent) write() {
 				if data.typ == message.Response {
 					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, err)
 				}
-				logger.Log.Error(err.Error())
+				logger.Log.Errorf("Failed to encode message: %s", err.Error())
 				break
 			}
 
@@ -388,7 +388,7 @@ func (a *Agent) write() {
 				if data.typ == message.Response {
 					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, err)
 				}
-				logger.Log.Error(err)
+				logger.Log.Errorf("Failed to encode packet: %s", err.Error())
 				break
 			}
 			// close agent if low-level Conn broken
@@ -397,7 +397,7 @@ func (a *Agent) write() {
 				if data.typ == message.Response {
 					metrics.ReportTimingFromCtx(data.ctx, a.metricsReporters, handlerType, err)
 				}
-				logger.Log.Error(err.Error())
+				logger.Log.Errorf("Failed to write response: %s", err.Error())
 				return
 			}
 			var e error

component.go

@@ -59,7 +59,7 @@ func startupComponents() {
 	// register all components
 	for _, c := range handlerComp {
 		if err := handlerService.Register(c.comp, c.opts); err != nil {
-			logger.Log.Error(err.Error())
+			logger.Log.Errorf("Failed to register handler: %s", err.Error())
 		}
 	}
 
@@ -69,7 +69,7 @@ func startupComponents() {
 			logger.Log.Warn("registered a remote component but remoteService is not running! skipping...")
 		} else {
 			if err := remoteService.Register(c.comp, c.opts); err != nil {
-				logger.Log.Error(err.Error())
+				logger.Log.Errorf("Failed to register remote: %s", err.Error())
 			}
 		}
 	}

service/handler.go

@@ -192,7 +192,7 @@ func (h *HandlerService) Handle(conn net.Conn) {
 		// (warning): decoder uses slice for performance, packet data should be copied before next Decode
 		packets, err := h.decoder.Decode(buf[:n])
 		if err != nil {
-			logger.Log.Error(err.Error())
+			logger.Log.Errorf("Failed to decode message: %s", err.Error())
 			return
 		}
 
@@ -204,7 +204,7 @@ func (h *HandlerService) Handle(conn net.Conn) {
 		// process all packet
 		for i := range packets {
 			if err := h.processPacket(a, packets[i]); err != nil {
-				logger.Log.Error(err.Error())
+				logger.Log.Errorf("Failed to process packet: %s", err.Error())
 				return
 			}
 		}
@@ -279,7 +279,7 @@ func (h *HandlerService) processMessage(a *agent.Agent, msg *message.Message) {
 
 	r, err := route.Decode(msg.Route)
 	if err != nil {
-		logger.Log.Error(err.Error())
+		logger.Log.Errorf("Failed to decode route: %s", err.Error())
 		a.AnswerWithError(ctx, msg.ID, e.NewError(err, e.ErrBadRequestCode))
 		return
 	}
@@ -317,7 +317,7 @@ func (h *HandlerService) localProcess(ctx context.Context, a *agent.Agent, route
 	ret, err := processHandlerMessage(ctx, route, h.serializer, a.Session, msg.Data, msg.Type, false)
 	if msg.Type != message.Notify {
 		if err != nil {
-			logger.Log.Error(err)
+			logger.Log.Errorf("Failed to process handler message: %s", err.Error())
 			a.AnswerWithError(ctx, mid, err)
 		} else {
 			a.Session.ResponseMID(ctx, mid, ret)

service/remote.go

@@ -98,13 +98,13 @@ func (r *RemoteService) remoteProcess(
 	switch msg.Type {
 	case message.Request:
 		if err != nil {
-			logger.Log.Error(err)
+			logger.Log.Errorf("Failed to process remote: %s", err.Error())
 			a.AnswerWithError(ctx, msg.ID, err)
 			return
 		}
 		err := a.Session.ResponseMID(ctx, msg.ID, res.Data)
 		if err != nil {
-			logger.Log.Error(err)
+			logger.Log.Errorf("Failed to respond remote: %s", err.Error())
 			a.AnswerWithError(ctx, msg.ID, err)
 		}
 	case message.Notify:

service/util.go

@@ -103,9 +103,6 @@ func executeBeforePipeline(ctx context.Context, data interface{}) (interface{},
 		for _, h := range pipeline.BeforeHandler.Handlers {
 			res, err = h(ctx, res)
 			if err != nil {
-				// TODO: not sure if this should be logged
-				// one may want to have a before filter that prevents handler execution
-				// example: auth
 				logger.Log.Debugf("pitaya/handler: broken pipeline: %s", err.Error())
 				return res, err
 			}
@@ -127,7 +124,7 @@ func executeAfterPipeline(ctx context.Context, res interface{}, err error) (inte
 func serializeReturn(ser serialize.Serializer, ret interface{}) ([]byte, error) {
 	res, err := util.SerializeOrRaw(ser, ret)
 	if err != nil {
-		logger.Log.Error(err.Error())
+		logger.Log.Errorf("Failed to serialize return: %s", err.Error())
 		res, err = util.GetErrorPayload(ser, err)
 		if err != nil {
 			logger.Log.Error("cannot serialize message and respond to the client ", err.Error())