chore: better mongo logs (#1965)

* chore: better mongo logs

* chore: add comments
master
Kevin Wan 2 years ago committed by GitHub
parent edfaa6d906
commit 6c94e4652e
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23

@ -328,5 +328,9 @@ func gzipFile(file string) error {
return err return err
} }
return os.Remove(file) // ignore errors on remove, it most happens on unit tests,
// it caused lots of troubles on GitHub actions.
// and even on production, remove errors are not important.
_ = os.Remove(file)
return nil
} }

@ -500,14 +500,28 @@ func (c *decoratedCollection) UpdateOne(ctx context.Context, filter interface{},
return return
} }
func (c *decoratedCollection) logDuration(ctx context.Context, method string, startTime time.Duration, err error, func (c *decoratedCollection) logDuration(ctx context.Context, method string,
docs ...interface{}) { startTime time.Duration, err error, docs ...interface{}) {
duration := timex.Since(startTime) duration := timex.Since(startTime)
logger := logx.WithContext(ctx).WithDuration(duration) logger := logx.WithContext(ctx).WithDuration(duration)
content, e := json.Marshal(docs) content, jerr := json.Marshal(docs)
if e != nil { // jerr should not be non-nil, but we don't care much on this,
logger.Error(e) // if non-nil, we just log without docs.
if jerr != nil {
if err != nil {
if duration > slowThreshold.Load() {
logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - fail(%s)", c.name, method, err.Error())
} else {
logger.Infof("mongo(%s) - %s - fail(%s)", c.name, method, err.Error())
}
} else {
if duration > slowThreshold.Load() {
logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - ok", c.name, method)
} else {
logger.Infof("mongo(%s) - %s - ok", c.name, method)
}
}
} else if err != nil { } else if err != nil {
if duration > slowThreshold.Load() { if duration > slowThreshold.Load() {
logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - fail(%s) - %s", logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - fail(%s) - %s",

@ -5,12 +5,12 @@ import (
"errors" "errors"
"strings" "strings"
"testing" "testing"
"time"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
"github.com/zeromicro/go-zero/core/breaker" "github.com/zeromicro/go-zero/core/breaker"
"github.com/zeromicro/go-zero/core/logx" "github.com/zeromicro/go-zero/core/logx"
"github.com/zeromicro/go-zero/core/stringx" "github.com/zeromicro/go-zero/core/stringx"
"github.com/zeromicro/go-zero/core/timex"
"go.mongodb.org/mongo-driver/bson" "go.mongodb.org/mongo-driver/bson"
"go.mongodb.org/mongo-driver/bson/primitive" "go.mongodb.org/mongo-driver/bson/primitive"
"go.mongodb.org/mongo-driver/mongo" "go.mongodb.org/mongo-driver/mongo"
@ -588,21 +588,40 @@ func Test_DecoratedCollectionLogDuration(t *testing.T) {
}() }()
buf.Reset() buf.Reset()
c.logDuration(context.Background(), "foo", time.Millisecond, nil, "bar") c.logDuration(context.Background(), "foo", timex.Now(), nil, "bar")
assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "foo")
assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "bar")
buf.Reset() buf.Reset()
c.logDuration(context.Background(), "foo", time.Millisecond, errors.New("bar"), make(chan int)) c.logDuration(context.Background(), "foo", timex.Now(), errors.New("bar"), make(chan int))
assert.Contains(t, buf.String(), "foo")
assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "bar")
buf.Reset() buf.Reset()
c.logDuration(context.Background(), "foo", slowThreshold.Load()+time.Millisecond, errors.New("bar")) c.logDuration(context.Background(), "foo", timex.Now(), nil, make(chan int))
assert.Contains(t, buf.String(), "foo")
buf.Reset()
c.logDuration(context.Background(), "foo", timex.Now()-slowThreshold.Load()*2,
nil, make(chan int))
assert.Contains(t, buf.String(), "foo")
assert.Contains(t, buf.String(), "slowcall")
buf.Reset()
c.logDuration(context.Background(), "foo", timex.Now()-slowThreshold.Load()*2,
errors.New("bar"), make(chan int))
assert.Contains(t, buf.String(), "foo")
assert.Contains(t, buf.String(), "bar")
assert.Contains(t, buf.String(), "slowcall")
buf.Reset()
c.logDuration(context.Background(), "foo", timex.Now()-slowThreshold.Load()*2,
errors.New("bar"))
assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "foo")
assert.Contains(t, buf.String(), "slowcall") assert.Contains(t, buf.String(), "slowcall")
buf.Reset() buf.Reset()
c.logDuration(context.Background(), "foo", slowThreshold.Load()+time.Millisecond, nil) c.logDuration(context.Background(), "foo", timex.Now()-slowThreshold.Load()*2, nil)
assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "foo")
assert.Contains(t, buf.String(), "slowcall") assert.Contains(t, buf.String(), "slowcall")
} }

Loading…
Cancel
Save