Skip to content

Commit

Permalink
This is an automated cherry-pick of pingcap#49215
Browse files Browse the repository at this point in the history
Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>
  • Loading branch information
hawkingrei authored and ti-chi-bot committed Dec 6, 2023
1 parent 51c38df commit e970b43
Show file tree
Hide file tree
Showing 13 changed files with 449 additions and 0 deletions.
4 changes: 4 additions & 0 deletions pkg/domain/domain.go
Original file line number Diff line number Diff line change
Expand Up @@ -2368,7 +2368,11 @@ func (do *Domain) syncIndexUsageWorker(owner owner.Manager) {
continue
}
if err := handle.GCIndexUsage(); err != nil {
<<<<<<< HEAD
logutil.BgLogger().Error("gc index usage failed", zap.String("category", "stats"), zap.Error(err))
=======
statslogutil.StatsLogger().Error("gc index usage failed", zap.Error(err))
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
}
}
}
Expand Down
14 changes: 14 additions & 0 deletions pkg/executor/test/partitiontest/main_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -12,4 +12,18 @@
// See the License for the specific language governing permissions and
// limitations under the License.

<<<<<<< HEAD:pkg/executor/test/partitiontest/main_test.go
package partitiontest
=======
package logutil

import (
"github.com/pingcap/tidb/pkg/util/logutil"
"go.uber.org/zap"
)

// StatsLogger with category "stats" is used to log statistic related messages.
func StatsLogger() *zap.Logger {
return logutil.BgLogger().With(zap.String("category", "stats"))
}
>>>>>>> 373608fe9df (*: fix log for statistics (#49215)):pkg/statistics/handle/logutil/logutil.go
48 changes: 48 additions & 0 deletions pkg/statistics/builder.go
Original file line number Diff line number Diff line change
Expand Up @@ -370,10 +370,58 @@ func BuildHistAndTopN(
topNList = pruneTopNItem(topNList, ndv, nullCount, sampleNum, count)

// Step2: exclude topn from samples
<<<<<<< HEAD
for i := int64(0); i < int64(len(samples)); i++ {
sampleBytes, err := getComparedBytes(samples[i].Value)
if err != nil {
return nil, nil, errors.Trace(err)
=======
if numTopN != 0 {
for i := int64(0); i < int64(len(samples)); i++ {
sampleBytes, err := getComparedBytes(samples[i].Value)
if err != nil {
return nil, nil, errors.Trace(err)
}
// For debugging invalid sample data.
var (
foundTwice bool
firstTimeSample types.Datum
)
for j := 0; j < len(topNList); j++ {
if bytes.Equal(sampleBytes, topNList[j].Encoded) {
// This should never happen, but we met this panic before, so we add this check here.
// See: https://github.com/pingcap/tidb/issues/35948
if foundTwice {
datumString, err := firstTimeSample.ToString()
if err != nil {
statslogutil.StatsLogger().Error("try to convert datum to string failed", zap.Error(err))
}

statslogutil.StatsLogger().Warn(
"invalid sample data",
zap.Bool("isColumn", isColumn),
zap.Int64("columnID", id),
zap.String("datum", datumString),
zap.Binary("sampleBytes", sampleBytes),
zap.Binary("topNBytes", topNList[j].Encoded),
)
// NOTE: if we don't return here, we may meet panic in the following code.
// The i may decrease to a negative value.
// We haven't fix the issue here, because we don't know how to
// remove the invalid sample data from the samples.
break
}
// First time to find the same value in topN: need to record the sample data for debugging.
firstTimeSample = samples[i].Value
// Found the same value in topn: need to skip over this value in samples.
copy(samples[i:], samples[uint64(i)+topNList[j].Count:])
samples = samples[:uint64(len(samples))-topNList[j].Count]
i--
foundTwice = true
continue
}
}
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
}
// For debugging invalid sample data.
var (
Expand Down
75 changes: 75 additions & 0 deletions pkg/statistics/handle/autoanalyze/autoanalyze.go
Original file line number Diff line number Diff line change
Expand Up @@ -134,15 +134,30 @@ func HandleAutoAnalyze(sctx sessionctx.Context,
is infoschema.InfoSchema) (analyzed bool) {
defer func() {
if r := recover(); r != nil {
<<<<<<< HEAD
logutil.BgLogger().Error("HandleAutoAnalyze panicked", zap.Any("error", r), zap.Stack("stack"))
=======
statslogutil.StatsLogger().Error(
"HandleAutoAnalyze panicked",
zap.Any("recover", r),
zap.Stack("stack"),
)
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
}
}()
dbs := is.AllSchemaNames()
parameters := getAutoAnalyzeParameters(sctx)
autoAnalyzeRatio := parseAutoAnalyzeRatio(parameters[variable.TiDBAutoAnalyzeRatio])
start, end, err := parseAnalyzePeriod(parameters[variable.TiDBAutoAnalyzeStartTime], parameters[variable.TiDBAutoAnalyzeEndTime])
if err != nil {
<<<<<<< HEAD
logutil.BgLogger().Error("parse auto analyze period failed", zap.String("category", "stats"), zap.Error(err))
=======
statslogutil.StatsLogger().Error(
"parse auto analyze period failed",
zap.Error(err),
)
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
return false
}
if !timeutil.WithinDayTimePeriod(start, end, time.Now()) {
Expand Down Expand Up @@ -182,8 +197,15 @@ func HandleAutoAnalyze(sctx sessionctx.Context,

lockedTables, err := statsHandle.GetLockedTables(tidsAndPids...)
if err != nil {
<<<<<<< HEAD
logutil.BgLogger().Error("check table lock failed",
zap.String("category", "stats"), zap.Error(err))
=======
statslogutil.StatsLogger().Error(
"check table lock failed",
zap.Error(err),
)
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
continue
}

Expand Down Expand Up @@ -251,7 +273,16 @@ func autoAnalyzeTable(sctx sessionctx.Context,
if err != nil {
return false
}
<<<<<<< HEAD
logutil.BgLogger().Info("auto analyze triggered", zap.String("category", "stats"), zap.String("sql", escaped), zap.String("reason", reason))
=======
statslogutil.StatsLogger().Info(
"auto analyze triggered",
zap.String("sql", escaped),
zap.String("reason", reason),
)

>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
tableStatsVer := sctx.GetSessionVars().AnalyzeVersion
statistics.CheckAnalyzeVerOnTable(statsTbl, &tableStatsVer)
execAutoAnalyze(sctx, statsHandle, tableStatsVer, sql, params...)
Expand All @@ -265,7 +296,15 @@ func autoAnalyzeTable(sctx sessionctx.Context,
if err != nil {
return false
}
<<<<<<< HEAD
logutil.BgLogger().Info("auto analyze for unanalyzed", zap.String("category", "stats"), zap.String("sql", escaped))
=======

statslogutil.StatsLogger().Info(
"auto analyze for unanalyzed indexes",
zap.String("sql", escaped),
)
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
tableStatsVer := sctx.GetSessionVars().AnalyzeVersion
statistics.CheckAnalyzeVerOnTable(statsTbl, &tableStatsVer)
execAutoAnalyze(sctx, statsHandle, tableStatsVer, sqlWithIdx, paramsWithIdx...)
Expand Down Expand Up @@ -331,9 +370,19 @@ func autoAnalyzePartitionTableInDynamicMode(sctx sessionctx.Context,
if partitionStatsTbl.Pseudo || partitionStatsTbl.RealtimeCount < AutoAnalyzeMinCnt {
continue
}
<<<<<<< HEAD
if needAnalyze, reason := NeedAnalyzeTable(partitionStatsTbl, 20*statsHandle.Lease(), ratio); needAnalyze {
partitionNames = append(partitionNames, def.Name.O)
logutil.BgLogger().Info("need to auto analyze", zap.String("category", "stats"),
=======
if needAnalyze, reason := NeedAnalyzeTable(
partitionStatsTbl,
ratio,
); needAnalyze {
needAnalyzePartitionNames = append(needAnalyzePartitionNames, def.Name.O)
statslogutil.StatsLogger().Info(
"need to auto analyze",
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
zap.String("database", db),
zap.String("table", tblInfo.Name.String()),
zap.String("partition", def.Name.O),
Expand All @@ -353,8 +402,14 @@ func autoAnalyzePartitionTableInDynamicMode(sctx sessionctx.Context,
sqlBuilder.WriteString(suffix)
return sqlBuilder.String()
}
<<<<<<< HEAD
if len(partitionNames) > 0 {
logutil.BgLogger().Info("start to auto analyze", zap.String("category", "stats"),
=======

if len(needAnalyzePartitionNames) > 0 {
statslogutil.StatsLogger().Info("start to auto analyze",
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
zap.String("database", db),
zap.String("table", tblInfo.Name.String()),
zap.Any("partitions", partitionNames),
Expand All @@ -368,8 +423,15 @@ func autoAnalyzePartitionTableInDynamicMode(sctx sessionctx.Context,
end = len(partitionNames)
}
sql := getSQL("analyze table %n.%n partition", "", end-start)
<<<<<<< HEAD
params := append([]interface{}{db, tblInfo.Name.O}, partitionNames[start:end]...)
logutil.BgLogger().Info("auto analyze triggered", zap.String("category", "stats"),
=======
params := append([]interface{}{db, tblInfo.Name.O}, needAnalyzePartitionNames[start:end]...)

statslogutil.StatsLogger().Info(
"auto analyze triggered",
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
zap.String("database", db),
zap.String("table", tblInfo.Name.String()),
zap.Any("partitions", partitionNames[start:end]))
Expand Down Expand Up @@ -400,7 +462,11 @@ func autoAnalyzePartitionTableInDynamicMode(sctx sessionctx.Context,
sql := getSQL("analyze table %n.%n partition", " index %n", end-start)
params := append([]interface{}{db, tblInfo.Name.O}, partitionNames[start:end]...)
params = append(params, idx.Name.O)
<<<<<<< HEAD
logutil.BgLogger().Info("auto analyze for unanalyzed", zap.String("category", "stats"),
=======
statslogutil.StatsLogger().Info("auto analyze for unanalyzed",
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
zap.String("database", db),
zap.String("table", tblInfo.Name.String()),
zap.String("index", idx.Name.String()),
Expand Down Expand Up @@ -432,7 +498,16 @@ func execAutoAnalyze(sctx sessionctx.Context,
if err1 != nil {
escaped = ""
}
<<<<<<< HEAD
logutil.BgLogger().Error("auto analyze failed", zap.String("category", "stats"), zap.String("sql", escaped), zap.Duration("cost_time", dur), zap.Error(err))
=======
statslogutil.StatsLogger().Error(
"auto analyze failed",
zap.String("sql", escaped),
zap.Duration("cost_time", dur),
zap.Error(err),
)
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
metrics.AutoAnalyzeCounter.WithLabelValues("failed").Inc()
} else {
metrics.AutoAnalyzeCounter.WithLabelValues("succ").Inc()
Expand Down
4 changes: 4 additions & 0 deletions pkg/statistics/handle/cache/statscache.go
Original file line number Diff line number Diff line change
Expand Up @@ -99,7 +99,11 @@ func (s *StatsCacheImpl) Update(is infoschema.InfoSchema) error {
tbl, err := s.statsHandle.TableStatsFromStorage(tableInfo, physicalID, false, 0)
// Error is not nil may mean that there are some ddl changes on this table, we will not update it.
if err != nil {
<<<<<<< HEAD
logutil.BgLogger().Error("error occurred when read table stats", zap.String("category", "stats"), zap.String("table", tableInfo.Name.O), zap.Error(err))
=======
statslogutil.StatsLogger().Error("error occurred when read table stats", zap.String("table", tableInfo.Name.O), zap.Error(err))
>>>>>>> 373608fe9df (*: fix log for statistics (#49215))
continue
}
if tbl == nil {
Expand Down
Loading

0 comments on commit e970b43

Please sign in to comment.