session: add session variable to log query string. (#5659)

session.go

@@ -657,7 +657,7 @@ func (s *session) executeStatement(connID uint64, stmtNode ast.StmtNode, stmt as
 	} else {
 		s.ClearValue(context.LastExecuteDDL)
 	}
-
+	logStmt(stmtNode, s.sessionVars)
 	startTS := time.Now()
 	recordSet, err := runStmt(s, stmt)
 	if err != nil {
@@ -671,7 +671,6 @@ func (s *session) executeStatement(connID uint64, stmtNode ast.StmtNode, stmt as
 	if recordSet != nil {
 		recordSets = append(recordSets, recordSet)
 	}
-	logCrucialStmt(stmtNode, s.sessionVars.User)
 	return recordSets, nil
 }
 
@@ -836,7 +835,7 @@ func (s *session) ExecutePreparedStmt(stmtID uint32, args ...interface{}) (ast.R
 	}
 	s.PrepareTxnCtx()
 	st := executor.CompileExecutePreparedStmt(s, stmtID, args...)
-
+	logQuery(st.OriginText(), s.sessionVars)
 	r, err := runStmt(s, st)
 	return r, errors.Trace(err)
 }
@@ -1287,17 +1286,27 @@ func (s *session) ShowProcess() util.ProcessInfo {
 	return pi
 }
 
-// logCrucialStmt logs some crucial SQL including: CREATE USER/GRANT PRIVILEGE/CHANGE PASSWORD/DDL etc.
-func logCrucialStmt(node ast.StmtNode, user *auth.UserIdentity) {
+// logStmt logs some crucial SQL including: CREATE USER/GRANT PRIVILEGE/CHANGE PASSWORD/DDL etc and normal SQL
+// if variable.ProcessGeneralLog is set.
+func logStmt(node ast.StmtNode, vars *variable.SessionVars) {
 	switch stmt := node.(type) {
 	case *ast.CreateUserStmt, *ast.DropUserStmt, *ast.AlterUserStmt, *ast.SetPwdStmt, *ast.GrantStmt,
 		*ast.RevokeStmt, *ast.AlterTableStmt, *ast.CreateDatabaseStmt, *ast.CreateIndexStmt, *ast.CreateTableStmt,
 		*ast.DropDatabaseStmt, *ast.DropIndexStmt, *ast.DropTableStmt, *ast.RenameTableStmt, *ast.TruncateTableStmt:
+		user := vars.User
 		if ss, ok := node.(ast.SensitiveStmtNode); ok {
 			log.Infof("[CRUCIAL OPERATION] %s (by %s).", ss.SecureText(), user)
 		} else {
 			log.Infof("[CRUCIAL OPERATION] %s (by %s).", stmt.Text(), user)
 		}
+	default:
+		logQuery(node.Text(), vars)
+	}
+}
+
+func logQuery(query string, vars *variable.SessionVars) {
+	if atomic.LoadUint32(&variable.ProcessGeneralLog) != 0 && !vars.InRestrictedSQL {
+		log.Infof("[%d] %s", vars.ConnectionID, query)
 	}
 }
 

sessionctx/variable/sysvar.go

@@ -620,6 +620,8 @@ var defaultSysVars = []*SysVar{
 	{ScopeSession, TiDBBatchDelete, boolToIntStr(DefBatchDelete)},
 	{ScopeSession, TiDBDMLBatchSize, strconv.Itoa(DefDMLBatchSize)},
 	{ScopeSession, TiDBCurrentTS, strconv.Itoa(DefCurretTS)},
+	/* The following variable is defined as session scope but is actually server scope. */
+	{ScopeSession, TiDBGeneralLog, strconv.Itoa(DefTiDBGeneralLog)},
 }
 
 // SetNamesVariables is the system variable names related to set names statements.

sessionctx/variable/tidb_vars.go

@@ -106,6 +106,9 @@ const (
 	// It controls the max row count of outer table when do index nested loop join without hint.
 	// After the row count of the inner table is accurate, this variable will be removed.
 	TiDBMaxRowCountForINLJ = "tidb_max_row_count_for_inlj"
+
+	// tidb_general_log is used to log every query in the server in info level.
+	TiDBGeneralLog = "tidb_general_log"
 )
 
 // Default TiDB system variable values.
@@ -124,4 +127,10 @@ const (
 	DefBatchDelete                = false
 	DefCurretTS                   = 0
 	DefDMLBatchSize               = 20000
+	DefTiDBGeneralLog             = 0
+)
+
+// Process global variables.
+var (
+	ProcessGeneralLog uint32
 )

sessionctx/varsutil/varsutil.go

@@ -17,6 +17,7 @@ import (
 	"fmt"
 	"strconv"
 	"strings"
+	"sync/atomic"
 	"time"
 
 	"github.com/juju/errors"
@@ -53,6 +54,8 @@ func GetSessionOnlySysVars(s *variable.SessionVars, key string) (string, bool, e
 	switch sysVar.Name {
 	case variable.TiDBCurrentTS:
 		return fmt.Sprintf("%d", s.TxnCtx.StartTS), true, nil
+	case variable.TiDBGeneralLog:
+		return fmt.Sprintf("%d", atomic.LoadUint32(&variable.ProcessGeneralLog)), true, nil
 	}
 	sVal, ok := s.Systems[key]
 	if ok {
@@ -167,6 +170,8 @@ func SetSessionSystemVar(vars *variable.SessionVars, name string, value types.Da
 		vars.MaxRowCountForINLJ = tidbOptPositiveInt(sVal, variable.DefMaxRowCountForINLJ)
 	case variable.TiDBCurrentTS:
 		return variable.ErrReadOnly
+	case variable.TiDBGeneralLog:
+		atomic.StoreUint32(&variable.ProcessGeneralLog, uint32(tidbOptPositiveInt(sVal, variable.DefTiDBGeneralLog)))
 	}
 	vars.Systems[name] = sVal
 	return nil