stats: log auto analyze fail reason (#9178) (#9189)

pingcap · Jan 28, 2019 · fda9e84 · fda9e84
1 parent 03e8aa3
commit fda9e84
Show file tree

Hide file tree

Showing 3 changed files with 25 additions and 29 deletions.
diff --git a/domain/domain.go b/domain/domain.go
@@ -933,10 +933,7 @@ func (do *Domain) autoAnalyzeWorker(owner owner.Manager) {
 		select {
 		case <-analyzeTicker.C:
 			if owner.IsOwner() {
-				err := statsHandle.HandleAutoAnalyze(do.InfoSchema())
-				if err != nil {
-					log.Error("[stats] auto analyze fail:", errors.ErrorStack(err))
-				}
+				statsHandle.HandleAutoAnalyze(do.InfoSchema())
 			}
 		case <-do.exit:
 			return

diff --git a/statistics/update.go b/statistics/update.go
@@ -699,13 +699,14 @@ func parseAnalyzePeriod(start, end string) (time.Time, time.Time, error) {
 }
 
 // HandleAutoAnalyze analyzes the newly created table or index.
-func (h *Handle) HandleAutoAnalyze(is infoschema.InfoSchema) error {
+func (h *Handle) HandleAutoAnalyze(is infoschema.InfoSchema) {
 	dbs := is.AllSchemaNames()
 	parameters := h.getAutoAnalyzeParameters()
 	autoAnalyzeRatio := parseAutoAnalyzeRatio(parameters[variable.TiDBAutoAnalyzeRatio])
 	start, end, err := parseAnalyzePeriod(parameters[variable.TiDBAutoAnalyzeStartTime], parameters[variable.TiDBAutoAnalyzeEndTime])
 	if err != nil {
-		return errors.Trace(err)
+		log.Errorf("[stats] parse auto analyze period failed: %v", errors.ErrorStack(err))
+		return
 	}
 	for _, db := range dbs {
 		tbls := is.SchemaTables(model.NewCIStr(db))
@@ -716,33 +717,34 @@ func (h *Handle) HandleAutoAnalyze(is infoschema.InfoSchema) error {
 			if pi == nil {
 				statsTbl := h.GetTableStats(tblInfo)
 				sql := fmt.Sprintf("analyze table %s", tblName)
-				analyzed, err := h.autoAnalyzeTable(tblInfo, statsTbl, start, end, autoAnalyzeRatio, sql)
+				analyzed := h.autoAnalyzeTable(tblInfo, statsTbl, start, end, autoAnalyzeRatio, sql)
 				if analyzed {
-					return err
+					return
 				}
 				continue
 			}
 			for _, def := range pi.Definitions {
 				sql := fmt.Sprintf("analyze table %s partition `%s`", tblName, def.Name.O)
 				statsTbl := h.GetPartitionStats(tblInfo, def.ID)
-				analyzed, err := h.autoAnalyzeTable(tblInfo, statsTbl, start, end, autoAnalyzeRatio, sql)
+				analyzed := h.autoAnalyzeTable(tblInfo, statsTbl, start, end, autoAnalyzeRatio, sql)
 				if analyzed {
-					return err
+					return
 				}
 				continue
 			}
 		}
 	}
-	return nil
+	return
 }
 
-func (h *Handle) autoAnalyzeTable(tblInfo *model.TableInfo, statsTbl *Table, start, end time.Time, ratio float64, sql string) (bool, error) {
+func (h *Handle) autoAnalyzeTable(tblInfo *model.TableInfo, statsTbl *Table, start, end time.Time, ratio float64, sql string) bool {
 	if statsTbl.Pseudo || statsTbl.Count < AutoAnalyzeMinCnt {
-		return false, nil
+		return false
 	}
 	if needAnalyze, reason := NeedAnalyzeTable(statsTbl, 20*h.Lease, ratio, start, end, time.Now()); needAnalyze {
 		log.Infof("[stats] %s, auto %s now", sql, reason)
-		return true, h.execAutoAnalyze(sql)
+		h.execAutoAnalyze(sql)
+		return true
 	}
 	for _, idx := range tblInfo.Indices {
 		if idx.State != model.StatePublic {
@@ -751,20 +753,22 @@ func (h *Handle) autoAnalyzeTable(tblInfo *model.TableInfo, statsTbl *Table, sta
 		if _, ok := statsTbl.Indices[idx.ID]; !ok {
 			sql = fmt.Sprintf("%s index `%s`", sql, idx.Name.O)
 			log.Infof("[stats] index unanalyzed, auto %s now", sql)
-			return true, h.execAutoAnalyze(sql)
+			h.execAutoAnalyze(sql)
+			return true
 		}
 	}
-	return false, nil
+	return false
 }
 
-func (h *Handle) execAutoAnalyze(sql string) error {
+func (h *Handle) execAutoAnalyze(sql string) {
 	startTime := time.Now()
 	_, _, err := h.restrictedExec.ExecRestrictedSQL(nil, sql)
-	metrics.AutoAnalyzeHistogram.Observe(time.Since(startTime).Seconds())
+	dur := time.Since(startTime)
+	metrics.AutoAnalyzeHistogram.Observe(dur.Seconds())
 	if err != nil {
+		log.Errorf("[stats] auto %v failed: %v, cost_time:%vs", sql, errors.ErrorStack(err), dur.Seconds())
 		metrics.AutoAnalyzeCounter.WithLabelValues("failed").Inc()
 	} else {
 		metrics.AutoAnalyzeCounter.WithLabelValues("succ").Inc()
 	}
-	return errors.Trace(err)
 }
diff --git a/statistics/update_test.go b/statistics/update_test.go
@@ -334,8 +334,7 @@ func (s *testStatsUpdateSuite) TestAutoUpdate(c *C) {
 	c.Assert(err, IsNil)
 	h.DumpStatsDeltaToKV(statistics.DumpAll)
 	h.Update(is)
-	err = h.HandleAutoAnalyze(is)
-	c.Assert(err, IsNil)
+	h.HandleAutoAnalyze(is)
 	h.Update(is)
 	stats = h.GetTableStats(tableInfo)
 	c.Assert(stats.Count, Equals, int64(1))
@@ -353,8 +352,7 @@ func (s *testStatsUpdateSuite) TestAutoUpdate(c *C) {
 	c.Assert(err, IsNil)
 	c.Assert(h.DumpStatsDeltaToKV(statistics.DumpAll), IsNil)
 	c.Assert(h.Update(is), IsNil)
-	err = h.HandleAutoAnalyze(is)
-	c.Assert(err, IsNil)
+	h.HandleAutoAnalyze(is)
 	h.Update(is)
 	stats = h.GetTableStats(tableInfo)
 	c.Assert(stats.Count, Equals, int64(2))
@@ -364,8 +362,7 @@ func (s *testStatsUpdateSuite) TestAutoUpdate(c *C) {
 	c.Assert(err, IsNil)
 	c.Assert(h.DumpStatsDeltaToKV(statistics.DumpAll), IsNil)
 	c.Assert(h.Update(is), IsNil)
-	err = h.HandleAutoAnalyze(is)
-	c.Assert(err, IsNil)
+	h.HandleAutoAnalyze(is)
 	h.Update(is)
 	stats = h.GetTableStats(tableInfo)
 	c.Assert(stats.Count, Equals, int64(3))
@@ -375,8 +372,7 @@ func (s *testStatsUpdateSuite) TestAutoUpdate(c *C) {
 	c.Assert(err, IsNil)
 	h.DumpStatsDeltaToKV(statistics.DumpAll)
 	h.Update(is)
-	err = h.HandleAutoAnalyze(is)
-	c.Assert(err, IsNil)
+	h.HandleAutoAnalyze(is)
 	h.Update(is)
 	stats = h.GetTableStats(tableInfo)
 	c.Assert(stats.Count, Equals, int64(4))
@@ -437,8 +433,7 @@ func (s *testStatsUpdateSuite) TestAutoUpdatePartition(c *C) {
 	testKit.MustExec("insert into t values (1)")
 	h.DumpStatsDeltaToKV(statistics.DumpAll)
 	h.Update(is)
-	err = h.HandleAutoAnalyze(is)
-	c.Assert(err, IsNil)
+	h.HandleAutoAnalyze(is)
 	stats = h.GetPartitionStats(tableInfo, pi.Definitions[0].ID)
 	c.Assert(stats.Count, Equals, int64(1))
 	c.Assert(stats.ModifyCount, Equals, int64(0))