diff --git a/remotecache/flashnode/flashnode_op.go b/remotecache/flashnode/flashnode_op.go index 7a80da1d1..2cd0049e5 100644 --- a/remotecache/flashnode/flashnode_op.go +++ b/remotecache/flashnode/flashnode_op.go @@ -313,7 +313,7 @@ func (f *FlashNode) opCachePutBlock(conn net.Conn, p *proto.Packet) (err error) p.LogMessage(p.GetOpMsg(), conn.RemoteAddr().String(), p.StartT, err)) p.PacketErrorWithBody(proto.OpErr, ([]byte)(err.Error())) if e := p.WriteToConn(conn); e != nil { - log.LogErrorf(logPrefix+" uniKey %v write to conn %v", uniKey, e) + log.LogWarnf(logPrefix+" uniKey %v write to conn %v", uniKey, e) } } }() @@ -363,7 +363,7 @@ func (f *FlashNode) opCachePutBlock(conn net.Conn, p *proto.Packet) (err error) } else { p.PacketOkReply() if err1 = p.WriteToConn(conn); err1 != nil { - log.LogErrorf(logPrefix+" blockKey %v write to conn %v", blockKey, err1) + log.LogWarnf(logPrefix+" blockKey %v write to conn %v", blockKey, err1) return } bgTime1 := stat.BeginStat() @@ -464,7 +464,7 @@ func (f *FlashNode) replyPutDataOk(ch *proto.CoonHandler, conn net.Conn, p *prot close(ch.Completed) for range ch.WaitAckChan { if ch.RemoteError = p.WriteToConn(conn); ch.RemoteError != nil { - log.LogErrorf(logPrefix+" reply to conn %v for write data", ch.RemoteError) + log.LogWarnf(logPrefix+" reply to conn %v for write data", ch.RemoteError) return } } @@ -477,7 +477,7 @@ func (f *FlashNode) opCacheBatchObjectGet(conn net.Conn, p *proto.Packet) (err e log.LogWarnf("action[opCacheBatchObjectGet] write to conn %v", err) p.PacketErrorWithBody(proto.OpErr, ([]byte)(err.Error())) if e := p.WriteToConn(conn); e != nil { - log.LogErrorf("action[opCacheBatchObjectGet] write to conn %v", e) + log.LogWarnf("action[opCacheBatchObjectGet] write to conn %v", e) } } stat.EndStat("FlashNode:opCacheBatchObjectGet", err, bgTime, 1) @@ -522,7 +522,7 @@ func (f *FlashNode) opCacheBatchObjectGet(conn net.Conn, p *proto.Packet) (err e p.ResultCode = proto.OpOk if err = p.MarshalDataPb(resp); err == nil { if e := p.WriteToConn(conn); e != nil { - log.LogErrorf("action[opCacheBatchObjectGet] write to conn %v", e) + log.LogWarnf("action[opCacheBatchObjectGet] write to conn %v", e) } } return @@ -637,7 +637,7 @@ func (f *FlashNode) opCacheObjectGet(conn net.Conn, p *proto.Packet) (err error) } p.PacketErrorWithBody(proto.OpErr, ([]byte)(err.Error())) if e := p.WriteToConn(conn); e != nil { - log.LogErrorf("action[opCacheObjectGet] reqID[%v] key:[%s] write to conn %v", reqID, uniKey, e) + log.LogWarnf("action[opCacheObjectGet] reqID[%v] key:[%s] write to conn %v", reqID, uniKey, e) } } }() @@ -976,7 +976,7 @@ func (f *FlashNode) doObjectReadRequest(ctx context.Context, conn net.Conn, req bgTime := stat.BeginStat() if errInner = reply.WriteToConnForOCS(conn, readDiskSize); errInner != nil { - log.LogErrorf("%s key:[%s] %s", action, block.GetBlockKey(), + log.LogWarnf("%s key:[%s] %s", action, block.GetBlockKey(), reply.LogMessage(reply.GetOpMsg(), conn.RemoteAddr().String(), reply.StartT, errInner)) return } diff --git a/sdk/data/stream/extent_handler.go b/sdk/data/stream/extent_handler.go index 382893dc1..dd823ca73 100644 --- a/sdk/data/stream/extent_handler.go +++ b/sdk/data/stream/extent_handler.go @@ -356,7 +356,7 @@ func (eh *ExtentHandler) sender() { log.LogDebugf("sender: done, eh(%v) size(%v) ek(%v)", eh, eh.size, eh.key) return case <-ticker.C: - log.LogErrorf("eh(%v) sender is still working", eh) + log.LogWarnf("eh(%v) sender is still working", eh) } } } diff --git a/sdk/remotecache/client.go b/sdk/remotecache/client.go index 3e6495788..658c1f511 100755 --- a/sdk/remotecache/client.go +++ b/sdk/remotecache/client.go @@ -214,6 +214,7 @@ func NewRemoteCacheClient(config *ClientConfig) (rc *RemoteCacheClient, err erro } if !config.FromFuse { changeFromRemote := make(chan struct{}) + startTime := time.Now() go func() { err = rc.updateRemoteCacheConfig() if err != nil { @@ -223,6 +224,7 @@ func NewRemoteCacheClient(config *ClientConfig) (rc *RemoteCacheClient, err erro if err != nil { log.LogWarnf("NewRemoteCacheClient: updateFlashGroups err %v", err) } + log.LogInfof("NewRemoteCacheClient: initialization completed in %v", time.Since(startTime)) close(changeFromRemote) }() if config.InitClientTime == 0 { @@ -231,7 +233,7 @@ func NewRemoteCacheClient(config *ClientConfig) (rc *RemoteCacheClient, err erro select { case <-changeFromRemote: case <-time.After(time.Duration(config.InitClientTime) * time.Second): - log.LogWarnf("NewRemoteCacheClient: init remote cache timeout for remote client") + log.LogWarnf("NewRemoteCacheClient: init remote cache timeout for remote client %v", startTime) err = proto.ErrorInitRemoteTimeout } } else { @@ -410,6 +412,7 @@ func (rc *RemoteCacheClient) IsClusterEnable() bool { } func (rc *RemoteCacheClient) UpdateFlashGroups() (err error) { + startTime := time.Now() var ( fgv proto.FlashGroupView newFlashGroups = btree.New(32) @@ -424,7 +427,9 @@ func (rc *RemoteCacheClient) UpdateFlashGroups() (err error) { return } } - log.LogDebugf("updateFlashGroups. get flashGroupView [%v]", fgv) + if log.EnableDebug() { + log.LogDebugf("updateFlashGroups. get flashGroupView [%v]", fgv) + } rc.SetClusterEnable(fgv.Enable && len(fgv.FlashGroups) != 0) if !fgv.Enable { rc.flashGroups = newFlashGroups @@ -448,8 +453,9 @@ func (rc *RemoteCacheClient) UpdateFlashGroups() (err error) { } } } - log.LogDebugf("updateFlashGroups: fgID(%v) newAdded hosts: %v", fg.ID, newAdded) - + if log.EnableDebug() { + log.LogDebugf("updateFlashGroups: fgID(%v) newAdded hosts: %v cost(%v)", fg.ID, newAdded, time.Since(startTime)) + } rc.updateHostLatency(newAdded) sortedHosts := rc.ClassifyHostsByAvgDelay(fg.ID, fg.Hosts) @@ -463,7 +469,9 @@ func (rc *RemoteCacheClient) UpdateFlashGroups() (err error) { } } rc.flashGroups = newFlashGroups - + if log.EnableInfo() { + log.LogInfof("updateFlashGroups: completed in %v", time.Since(startTime)) + } return }