Optimize log trace (#23431)

Signed-off-by: longjiquan <jiquan.long@zilliz.com>
This commit is contained in:
Jiquan Long 2023-04-17 11:00:30 +08:00 committed by GitHub
parent f603456b72
commit adfa415b74
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 45 additions and 37 deletions

View File

@ -76,7 +76,7 @@ func newServerBroker(s *Core) *ServerBroker {
}
func (b *ServerBroker) ReleaseCollection(ctx context.Context, collectionID UniqueID) error {
log.Info("releasing collection", zap.Int64("collection", collectionID))
log.Ctx(ctx).Info("releasing collection", zap.Int64("collection", collectionID))
resp, err := b.s.queryCoord.ReleaseCollection(ctx, &querypb.ReleaseCollectionRequest{
Base: commonpbutil.NewMsgBase(commonpbutil.WithMsgType(commonpb.MsgType_ReleaseCollection)),
@ -91,7 +91,7 @@ func (b *ServerBroker) ReleaseCollection(ctx context.Context, collectionID Uniqu
return fmt.Errorf("failed to release collection, code: %s, reason: %s", resp.GetErrorCode(), resp.GetReason())
}
log.Info("done to release collection", zap.Int64("collection", collectionID))
log.Ctx(ctx).Info("done to release collection", zap.Int64("collection", collectionID))
return nil
}
@ -162,7 +162,7 @@ func toKeyDataPairs(m map[string][]byte) []*commonpb.KeyDataPair {
}
func (b *ServerBroker) WatchChannels(ctx context.Context, info *watchInfo) error {
log.Info("watching channels", zap.Uint64("ts", info.ts), zap.Int64("collection", info.collectionID), zap.Strings("vChannels", info.vChannels))
log.Ctx(ctx).Info("watching channels", zap.Uint64("ts", info.ts), zap.Int64("collection", info.collectionID), zap.Strings("vChannels", info.vChannels))
resp, err := b.s.dataCoord.WatchChannels(ctx, &datapb.WatchChannelsRequest{
CollectionID: info.collectionID,
@ -178,7 +178,7 @@ func (b *ServerBroker) WatchChannels(ctx context.Context, info *watchInfo) error
return fmt.Errorf("failed to watch channels, code: %s, reason: %s", resp.GetStatus().GetErrorCode(), resp.GetStatus().GetReason())
}
log.Info("done to watch channels", zap.Uint64("ts", info.ts), zap.Int64("collection", info.collectionID), zap.Strings("vChannels", info.vChannels))
log.Ctx(ctx).Info("done to watch channels", zap.Uint64("ts", info.ts), zap.Int64("collection", info.collectionID), zap.Strings("vChannels", info.vChannels))
return nil
}
@ -221,6 +221,8 @@ func (b *ServerBroker) GetSegmentStates(ctx context.Context, req *datapb.GetSegm
}
func (b *ServerBroker) DropCollectionIndex(ctx context.Context, collID UniqueID, partIDs []UniqueID) error {
log.Ctx(ctx).Info("dropping collection index", zap.Int64("collection", collID), zap.Int64s("partitions", partIDs))
rsp, err := b.s.dataCoord.DropIndex(ctx, &indexpb.DropIndexRequest{
CollectionID: collID,
PartitionIDs: partIDs,
@ -233,6 +235,9 @@ func (b *ServerBroker) DropCollectionIndex(ctx context.Context, collID UniqueID,
if rsp.ErrorCode != commonpb.ErrorCode_Success {
return fmt.Errorf(rsp.Reason)
}
log.Ctx(ctx).Info("done to drop collection index", zap.Int64("collection", collID), zap.Int64s("partitions", partIDs))
return nil
}

View File

@ -168,7 +168,7 @@ func (mt *MetaTable) AddCollection(ctx context.Context, coll *model.Collection)
}
mt.collName2ID[coll.Name] = coll.CollectionID
mt.collID2Meta[coll.CollectionID] = coll.Clone()
log.Info("add collection to meta table", zap.String("collection", coll.Name),
log.Ctx(ctx).Info("add collection to meta table", zap.String("collection", coll.Name),
zap.Int64("id", coll.CollectionID), zap.Uint64("ts", coll.CreateTime))
return nil
}
@ -198,7 +198,7 @@ func (mt *MetaTable) ChangeCollectionState(ctx context.Context, collectionID Uni
metrics.RootCoordNumOfPartitions.WithLabelValues().Sub(float64(coll.GetPartitionNum(true)))
}
log.Info("change collection state", zap.Int64("collection", collectionID),
log.Ctx(ctx).Info("change collection state", zap.Int64("collection", collectionID),
zap.String("state", state.String()), zap.Uint64("ts", ts))
return nil
@ -259,7 +259,7 @@ func (mt *MetaTable) RemoveCollection(ctx context.Context, collectionID UniqueID
mt.removeAllNamesIfMatchedInternal(collectionID, allNames)
mt.removeCollectionByIDInternal(collectionID)
log.Info("remove collection", zap.String("name", name), zap.Int64("id", collectionID), zap.Strings("aliases", aliases))
log.Ctx(ctx).Info("remove collection", zap.String("name", name), zap.Int64("id", collectionID), zap.Strings("aliases", aliases))
return nil
}
@ -520,7 +520,7 @@ func (mt *MetaTable) AddPartition(ctx context.Context, partition *model.Partitio
metrics.RootCoordNumOfPartitions.WithLabelValues().Inc()
log.Info("add partition to meta table",
log.Ctx(ctx).Info("add partition to meta table",
zap.Int64("collection", partition.CollectionID), zap.String("partition", partition.PartitionName),
zap.Int64("partitionid", partition.PartitionID), zap.Uint64("ts", partition.PartitionCreatedTimestamp))
@ -547,14 +547,14 @@ func (mt *MetaTable) ChangePartitionState(ctx context.Context, collectionID Uniq
switch state {
case pb.PartitionState_PartitionCreated:
log.Warn("[should not happen] change partition to created",
log.Ctx(ctx).Warn("[should not happen] change partition to created",
zap.String("collection", coll.Name), zap.Int64("collection id", coll.CollectionID),
zap.String("partition", clone.PartitionName), zap.Int64("partition id", clone.PartitionID))
default:
metrics.RootCoordNumOfPartitions.WithLabelValues().Dec()
}
log.Info("change partition state", zap.Int64("collection", collectionID),
log.Ctx(ctx).Info("change partition state", zap.Int64("collection", collectionID),
zap.Int64("partition", partitionID), zap.String("state", state.String()),
zap.Uint64("ts", ts))

View File

@ -761,7 +761,7 @@ func (c *Core) CreateCollection(ctx context.Context, in *milvuspb.CreateCollecti
}
if err := c.scheduler.AddTask(t); err != nil {
log.Ctx(ctx).Error("failed to enqueue request to create collection",
log.Ctx(ctx).Info("failed to enqueue request to create collection",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("name", in.GetCollectionName()))
@ -771,7 +771,7 @@ func (c *Core) CreateCollection(ctx context.Context, in *milvuspb.CreateCollecti
}
if err := t.WaitToFinish(); err != nil {
log.Ctx(ctx).Error("failed to create collection",
log.Ctx(ctx).Info("failed to create collection",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("name", in.GetCollectionName()),
@ -814,7 +814,7 @@ func (c *Core) DropCollection(ctx context.Context, in *milvuspb.DropCollectionRe
}
if err := c.scheduler.AddTask(t); err != nil {
log.Ctx(ctx).Error("failed to enqueue request to drop collection", zap.String("role", typeutil.RootCoordRole),
log.Ctx(ctx).Info("failed to enqueue request to drop collection", zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("name", in.GetCollectionName()))
@ -823,7 +823,7 @@ func (c *Core) DropCollection(ctx context.Context, in *milvuspb.DropCollectionRe
}
if err := t.WaitToFinish(); err != nil {
log.Ctx(ctx).Error("failed to drop collection", zap.String("role", typeutil.RootCoordRole),
log.Ctx(ctx).Info("failed to drop collection", zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("name", in.GetCollectionName()),
zap.Uint64("ts", t.GetTs()))
@ -866,7 +866,7 @@ func (c *Core) HasCollection(ctx context.Context, in *milvuspb.HasCollectionRequ
}
if err := c.scheduler.AddTask(t); err != nil {
log.Warn("failed to enqueue request to has collection", zap.Error(err))
log.Info("failed to enqueue request to has collection", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("HasCollection", metrics.FailLabel).Inc()
return &milvuspb.BoolResponse{
Status: merr.Status(err),
@ -874,7 +874,7 @@ func (c *Core) HasCollection(ctx context.Context, in *milvuspb.HasCollectionRequ
}
if err := t.WaitToFinish(); err != nil {
log.Warn("failed to has collection", zap.Error(err))
log.Info("failed to has collection", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("HasCollection", metrics.FailLabel).Inc()
return &milvuspb.BoolResponse{
Status: merr.Status(err),
@ -953,7 +953,7 @@ func (c *Core) describeCollectionImpl(ctx context.Context, in *milvuspb.Describe
}
if err := c.scheduler.AddTask(t); err != nil {
log.Warn("failed to enqueue request to describe collection", zap.Error(err))
log.Info("failed to enqueue request to describe collection", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("DescribeCollection", metrics.FailLabel).Inc()
return &milvuspb.DescribeCollectionResponse{
// TODO: use commonpb.ErrorCode_CollectionNotExists. SDK use commonpb.ErrorCode_UnexpectedError now.
@ -963,7 +963,7 @@ func (c *Core) describeCollectionImpl(ctx context.Context, in *milvuspb.Describe
}
if err := t.WaitToFinish(); err != nil {
log.Warn("failed to describe collection", zap.Error(err))
log.Info("failed to describe collection", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("DescribeCollection", metrics.FailLabel).Inc()
return &milvuspb.DescribeCollectionResponse{
// TODO: use commonpb.ErrorCode_CollectionNotExists. SDK use commonpb.ErrorCode_UnexpectedError now.
@ -1019,7 +1019,7 @@ func (c *Core) ShowCollections(ctx context.Context, in *milvuspb.ShowCollections
}
if err := c.scheduler.AddTask(t); err != nil {
log.Warn("failed to enqueue request to show collections", zap.Error(err))
log.Info("failed to enqueue request to show collections", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("ShowCollections", metrics.FailLabel).Inc()
return &milvuspb.ShowCollectionsResponse{
Status: merr.Status(err),
@ -1027,7 +1027,7 @@ func (c *Core) ShowCollections(ctx context.Context, in *milvuspb.ShowCollections
}
if err := t.WaitToFinish(); err != nil {
log.Warn("failed to show collections", zap.Error(err))
log.Info("failed to show collections", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("ShowCollections", metrics.FailLabel).Inc()
return &milvuspb.ShowCollectionsResponse{
Status: merr.Status(err),
@ -1119,7 +1119,7 @@ func (c *Core) CreatePartition(ctx context.Context, in *milvuspb.CreatePartition
}
if err := c.scheduler.AddTask(t); err != nil {
log.Ctx(ctx).Error("failed to enqueue request to create partition",
log.Ctx(ctx).Info("failed to enqueue request to create partition",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("collection", in.GetCollectionName()),
@ -1130,7 +1130,7 @@ func (c *Core) CreatePartition(ctx context.Context, in *milvuspb.CreatePartition
}
if err := t.WaitToFinish(); err != nil {
log.Ctx(ctx).Error("failed to create partition",
log.Ctx(ctx).Info("failed to create partition",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("collection", in.GetCollectionName()),
@ -1176,7 +1176,7 @@ func (c *Core) DropPartition(ctx context.Context, in *milvuspb.DropPartitionRequ
}
if err := c.scheduler.AddTask(t); err != nil {
log.Ctx(ctx).Error("failed to enqueue request to drop partition",
log.Ctx(ctx).Info("failed to enqueue request to drop partition",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("collection", in.GetCollectionName()),
@ -1186,7 +1186,7 @@ func (c *Core) DropPartition(ctx context.Context, in *milvuspb.DropPartitionRequ
return merr.Status(err), nil
}
if err := t.WaitToFinish(); err != nil {
log.Ctx(ctx).Error("failed to drop partition",
log.Ctx(ctx).Info("failed to drop partition",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("collection", in.GetCollectionName()),
@ -1234,7 +1234,7 @@ func (c *Core) HasPartition(ctx context.Context, in *milvuspb.HasPartitionReques
}
if err := c.scheduler.AddTask(t); err != nil {
log.Warn("failed to enqueue request to has partition", zap.Error(err))
log.Info("failed to enqueue request to has partition", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("HasPartition", metrics.FailLabel).Inc()
return &milvuspb.BoolResponse{
Status: merr.Status(err),
@ -1242,7 +1242,7 @@ func (c *Core) HasPartition(ctx context.Context, in *milvuspb.HasPartitionReques
}
if err := t.WaitToFinish(); err != nil {
log.Warn("failed to has partition", zap.Error(err))
log.Info("failed to has partition", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("HasPartition", metrics.FailLabel).Inc()
return &milvuspb.BoolResponse{
Status: merr.Status(err),
@ -1267,7 +1267,10 @@ func (c *Core) showPartitionsImpl(ctx context.Context, in *milvuspb.ShowPartitio
metrics.RootCoordDDLReqCounter.WithLabelValues("ShowPartitions", metrics.TotalLabel).Inc()
tr := timerecord.NewTimeRecorder("ShowPartitions")
log := log.Ctx(ctx).With(zap.String("collection", in.GetCollectionName()), zap.Bool("allowUnavailable", allowUnavailable))
log := log.Ctx(ctx).With(zap.String("collection", in.GetCollectionName()),
zap.Int64("collection_id", in.GetCollectionID()),
zap.Strings("partitions", in.GetPartitionNames()),
zap.Bool("allowUnavailable", allowUnavailable))
log.Info("received request to show partitions")
@ -1279,7 +1282,7 @@ func (c *Core) showPartitionsImpl(ctx context.Context, in *milvuspb.ShowPartitio
}
if err := c.scheduler.AddTask(t); err != nil {
log.Warn("failed to enqueue request to show partitions", zap.Error(err))
log.Info("failed to enqueue request to show partitions", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("ShowPartitions", metrics.FailLabel).Inc()
return &milvuspb.ShowPartitionsResponse{
Status: merr.Status(err),
@ -1288,7 +1291,7 @@ func (c *Core) showPartitionsImpl(ctx context.Context, in *milvuspb.ShowPartitio
}
if err := t.WaitToFinish(); err != nil {
log.Warn("failed to show partitions", zap.Error(err))
log.Info("failed to show partitions", zap.Error(err))
metrics.RootCoordDDLReqCounter.WithLabelValues("ShowPartitions", metrics.FailLabel).Inc()
return &milvuspb.ShowPartitionsResponse{
Status: merr.Status(err),
@ -1509,7 +1512,7 @@ func (c *Core) CreateAlias(ctx context.Context, in *milvuspb.CreateAliasRequest)
}
if err := c.scheduler.AddTask(t); err != nil {
log.Warn("failed to enqueue request to create alias",
log.Ctx(ctx).Info("failed to enqueue request to create alias",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("alias", in.GetAlias()),
@ -1520,7 +1523,7 @@ func (c *Core) CreateAlias(ctx context.Context, in *milvuspb.CreateAliasRequest)
}
if err := t.WaitToFinish(); err != nil {
log.Warn("failed to create alias",
log.Ctx(ctx).Info("failed to create alias",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("alias", in.GetAlias()),
@ -1534,7 +1537,7 @@ func (c *Core) CreateAlias(ctx context.Context, in *milvuspb.CreateAliasRequest)
metrics.RootCoordDDLReqCounter.WithLabelValues("CreateAlias", metrics.SuccessLabel).Inc()
metrics.RootCoordDDLReqLatency.WithLabelValues("CreateAlias").Observe(float64(tr.ElapseSpan().Milliseconds()))
log.Info("done to create alias",
log.Ctx(ctx).Info("done to create alias",
zap.String("role", typeutil.RootCoordRole),
zap.String("alias", in.GetAlias()),
zap.String("collection", in.GetCollectionName()),
@ -1565,7 +1568,7 @@ func (c *Core) DropAlias(ctx context.Context, in *milvuspb.DropAliasRequest) (*c
}
if err := c.scheduler.AddTask(t); err != nil {
log.Warn("failed to enqueue request to drop alias",
log.Ctx(ctx).Info("failed to enqueue request to drop alias",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("alias", in.GetAlias()))
@ -1575,7 +1578,7 @@ func (c *Core) DropAlias(ctx context.Context, in *milvuspb.DropAliasRequest) (*c
}
if err := t.WaitToFinish(); err != nil {
log.Warn("failed to drop alias",
log.Ctx(ctx).Info("failed to drop alias",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("alias", in.GetAlias()),
@ -1588,7 +1591,7 @@ func (c *Core) DropAlias(ctx context.Context, in *milvuspb.DropAliasRequest) (*c
metrics.RootCoordDDLReqCounter.WithLabelValues("DropAlias", metrics.SuccessLabel).Inc()
metrics.RootCoordDDLReqLatency.WithLabelValues("DropAlias").Observe(float64(tr.ElapseSpan().Milliseconds()))
log.Info("done to drop alias",
log.Ctx(ctx).Info("done to drop alias",
zap.String("role", typeutil.RootCoordRole),
zap.String("alias", in.GetAlias()),
zap.Uint64("ts", t.GetTs()))
@ -1619,7 +1622,7 @@ func (c *Core) AlterAlias(ctx context.Context, in *milvuspb.AlterAliasRequest) (
}
if err := c.scheduler.AddTask(t); err != nil {
log.Warn("failed to enqueue request to alter alias",
log.Ctx(ctx).Info("failed to enqueue request to alter alias",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("alias", in.GetAlias()),
@ -1630,7 +1633,7 @@ func (c *Core) AlterAlias(ctx context.Context, in *milvuspb.AlterAliasRequest) (
}
if err := t.WaitToFinish(); err != nil {
log.Warn("failed to alter alias",
log.Ctx(ctx).Info("failed to alter alias",
zap.String("role", typeutil.RootCoordRole),
zap.Error(err),
zap.String("alias", in.GetAlias()),