From 81c67aced4060af35a6b9495e7b512c07d573509 Mon Sep 17 00:00:00 2001
From: lysu <sulifx@gmail.com>
Date: Mon, 30 Mar 2020 15:41:55 +0800
Subject: [PATCH] server, session: refine mysql handshake error log

---
 server/conn.go     | 32 +++++++++++++++++++++++++++++---
 server/server.go   |  1 -
 session/session.go |  5 -----
 3 files changed, 29 insertions(+), 9 deletions(-)

diff --git a/server/conn.go b/server/conn.go
index a71c2fb62c67c..19a82c09c66ab 100644
--- a/server/conn.go
+++ b/server/conn.go
@@ -168,6 +168,11 @@ func (cc *clientConn) String() string {
 // After handshake, client can send sql query to server.
 func (cc *clientConn) handshake(ctx context.Context) error {
 	if err := cc.writeInitialHandshake(); err != nil {
+		if errors.Cause(err) == io.EOF {
+			logutil.Logger(ctx).Info("Could not send handshake due to connection has be closed by client-side")
+		} else {
+			terror.Log(err)
+		}
 		return err
 	}
 	if err := cc.readOptionalSSLRequestAndHandshakeResponse(ctx); err != nil {
@@ -188,10 +193,18 @@ func (cc *clientConn) handshake(ctx context.Context) error {
 	err := cc.writePacket(data)
 	cc.pkt.sequence = 0
 	if err != nil {
+		err = errors.SuspendStack(err)
+		logutil.Logger(ctx).Debug("write response to client failed", zap.Error(err))
 		return err
 	}
 
-	return cc.flush()
+	err = cc.flush()
+	if err != nil {
+		err = errors.SuspendStack(err)
+		logutil.Logger(ctx).Debug("flush response to client failed", zap.Error(err))
+		return err
+	}
+	return err
 }
 
 func (cc *clientConn) Close() error {
@@ -471,6 +484,12 @@ func (cc *clientConn) readOptionalSSLRequestAndHandshakeResponse(ctx context.Con
 	// Read a packet. It may be a SSLRequest or HandshakeResponse.
 	data, err := cc.readPacket()
 	if err != nil {
+		err = errors.SuspendStack(err)
+		if errors.Cause(err) == io.EOF {
+			logutil.Logger(ctx).Info("wait handshake response fail due to connection has be closed by client-side")
+		} else {
+			logutil.Logger(ctx).Error("wait handshake response fail", zap.Error(err))
+		}
 		return err
 	}
 
@@ -493,6 +512,7 @@ func (cc *clientConn) readOptionalSSLRequestAndHandshakeResponse(ctx context.Con
 	}
 
 	if err != nil {
+		terror.Log(err)
 		return err
 	}
 
@@ -506,6 +526,7 @@ func (cc *clientConn) readOptionalSSLRequestAndHandshakeResponse(ctx context.Con
 			// Read the following HandshakeResponse packet.
 			data, err = cc.readPacket()
 			if err != nil {
+				logutil.Logger(ctx).Warn("read handshake response failure after upgrade to TLS", zap.Error(err))
 				return err
 			}
 			if isOldVersion {
@@ -514,11 +535,14 @@ func (cc *clientConn) readOptionalSSLRequestAndHandshakeResponse(ctx context.Con
 				pos, err = parseHandshakeResponseHeader(ctx, &resp, data)
 			}
 			if err != nil {
+				terror.Log(err)
 				return err
 			}
 		}
 	} else if config.GetGlobalConfig().Security.RequireSecureTransport {
-		return errSecureTransportRequired.FastGenByArgs()
+		err := errSecureTransportRequired.FastGenByArgs()
+		terror.Log(err)
+		return err
 	}
 
 	// Read the remaining part of the packet.
@@ -528,6 +552,7 @@ func (cc *clientConn) readOptionalSSLRequestAndHandshakeResponse(ctx context.Con
 		err = parseHandshakeResponseBody(ctx, &resp, data, pos)
 	}
 	if err != nil {
+		terror.Log(err)
 		return err
 	}
 
@@ -538,6 +563,7 @@ func (cc *clientConn) readOptionalSSLRequestAndHandshakeResponse(ctx context.Con
 	cc.attrs = resp.Attrs
 
 	err = cc.openSessionAndDoAuth(resp.Auth)
+	logutil.Logger(ctx).Warn("open new session failure", zap.Error(err))
 	return err
 }
 
@@ -575,7 +601,7 @@ func (cc *clientConn) openSessionAndDoAuth(authData []byte) error {
 		return err
 	}
 	if !cc.ctx.Auth(&auth.UserIdentity{Username: cc.user, Hostname: host}, authData, cc.salt) {
-		return errAccessDenied.GenWithStackByArgs(cc.user, host, hasPassword)
+		return errAccessDenied.FastGenByArgs(cc.user, host, hasPassword)
 	}
 	if cc.dbname != "" {
 		err = cc.useDB(context.Background(), cc.dbname)
diff --git a/server/server.go b/server/server.go
index 145ab54b16bb3..faac3b105a187 100644
--- a/server/server.go
+++ b/server/server.go
@@ -346,7 +346,6 @@ func (s *Server) Close() {
 func (s *Server) onConn(conn *clientConn) {
 	ctx := logutil.WithConnID(context.Background(), conn.connectionID)
 	if err := conn.handshake(ctx); err != nil {
-		terror.Log(err)
 		if plugin.IsEnable(plugin.Audit) {
 			conn.ctx.GetSessionVars().ConnectionInfo = conn.connectInfo()
 		}
diff --git a/session/session.go b/session/session.go
index 4f5d0be8696c9..828651999fc2b 100644
--- a/session/session.go
+++ b/session/session.go
@@ -1377,8 +1377,6 @@ func (s *session) Auth(user *auth.UserIdentity, authentication []byte, salt []by
 		s.sessionVars.ActiveRoles = pm.GetDefaultRoles(user.AuthUsername, user.AuthHostname)
 		return true
 	} else if user.Hostname == variable.DefHostname {
-		logutil.Logger(context.Background()).Error("user connection verification failed",
-			zap.Stringer("user", user))
 		return false
 	}
 
@@ -1396,9 +1394,6 @@ func (s *session) Auth(user *auth.UserIdentity, authentication []byte, salt []by
 			return true
 		}
 	}
-
-	logutil.Logger(context.Background()).Error("user connection verification failed",
-		zap.Stringer("user", user))
 	return false
 }