diff --git a/core/stores/mon/collection.go b/core/stores/mon/collection.go index 669d43f5..a909bb02 100644 --- a/core/stores/mon/collection.go +++ b/core/stores/mon/collection.go @@ -501,10 +501,11 @@ func (c *decoratedCollection) UpdateOne(ctx context.Context, filter, update any, func (c *decoratedCollection) logDuration(ctx context.Context, method string, startTime time.Duration, err error, docs ...any) { - logDurationWithDoc(ctx, c.name, method, startTime, err, docs...) + logDurationWithDocs(ctx, c.name, method, startTime, err, docs...) } -func (c *decoratedCollection) logDurationSimple(ctx context.Context, method string, startTime time.Duration, err error) { +func (c *decoratedCollection) logDurationSimple(ctx context.Context, method string, + startTime time.Duration, err error) { logDuration(ctx, c.name, method, startTime, err) } diff --git a/core/stores/mon/options.go b/core/stores/mon/options.go index 9ce06ad6..4097328f 100644 --- a/core/stores/mon/options.go +++ b/core/stores/mon/options.go @@ -22,13 +22,13 @@ type ( Option func(opts *options) ) -// DisableLog disables logging of mongo command, includes info and slow logs. +// DisableLog disables logging of mongo commands, includes info and slow logs. func DisableLog() { logMon.Set(false) logSlowMon.Set(false) } -// DisableInfoLog disables info logging of mongo command, but keeps slow logs. +// DisableInfoLog disables info logging of mongo commands, but keeps slow logs. func DisableInfoLog() { logMon.Set(false) } diff --git a/core/stores/mon/util.go b/core/stores/mon/util.go index 43f0ac3e..03e9a70c 100644 --- a/core/stores/mon/util.go +++ b/core/stores/mon/util.go @@ -3,7 +3,6 @@ package mon import ( "context" "encoding/json" - "errors" "strings" "time" @@ -13,53 +12,50 @@ import ( const mongoAddrSep = "," -var errPlaceholder = errors.New("placeholder") - // FormatAddr formats mongo hosts to a string. func FormatAddr(hosts []string) string { return strings.Join(hosts, mongoAddrSep) } func logDuration(ctx context.Context, name, method string, startTime time.Duration, err error) { - logDurationWithDoc(ctx, name, method, startTime, err) + duration := timex.Since(startTime) + logger := logx.WithContext(ctx).WithDuration(duration) + if err != nil { + logger.Errorf("mongo(%s) - %s - fail(%s)", name, method, err.Error()) + return + } + + if logSlowMon.True() && duration > slowThreshold.Load() { + logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - ok", name, method) + } else if logMon.True() { + logger.Infof("mongo(%s) - %s - ok", name, method) + } } -func logDurationWithDoc(ctx context.Context, name, method string, - startTime time.Duration, err error, docs ...any) { +func logDurationWithDocs(ctx context.Context, name, method string, startTime time.Duration, + err error, docs ...any) { duration := timex.Since(startTime) logger := logx.WithContext(ctx).WithDuration(duration) - var content []byte - jerr := errPlaceholder - if len(docs) > 0 { - content, jerr = json.Marshal(docs) - } - if err == nil { - // jerr should not be non-nil, but we don't care much on this, - // if non-nil, we just log without docs. - if jerr != nil { - if logSlowMon.True() && duration > slowThreshold.Load() { - logger.Slowf("mongo(%s) - slowcall - %s - ok", name, method) - } else if logMon.True() { - logger.Infof("mongo(%s) - %s - ok", name, method) - } - } else { - if logSlowMon.True() && duration > slowThreshold.Load() { - logger.Slowf("mongo(%s) - slowcall - %s - ok - %s", - name, method, string(content)) - } else if logMon.True() { - logger.Infof("mongo(%s) - %s - ok - %s", - name, method, string(content)) - } + content, jerr := json.Marshal(docs) + // jerr should not be non-nil, but we don't care much on this, + // if non-nil, we just log without docs. + if jerr != nil { + if err != nil { + logger.Errorf("mongo(%s) - %s - fail(%s)", name, method, err.Error()) + } else if logSlowMon.True() && duration > slowThreshold.Load() { + logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - ok", name, method) + } else if logMon.True() { + logger.Infof("mongo(%s) - %s - ok", name, method) } - return } - if jerr != nil { - logger.Errorf("mongo(%s) - %s - fail(%s)", name, method, err.Error()) - } else { - logger.Errorf("mongo(%s) - %s - fail(%s) - %s", - name, method, err.Error(), string(content)) + if err != nil { + logger.Errorf("mongo(%s) - %s - fail(%s) - %s", name, method, err.Error(), string(content)) + } else if logSlowMon.True() && duration > slowThreshold.Load() { + logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - ok - %s", name, method, string(content)) + } else if logMon.True() { + logger.Infof("mongo(%s) - %s - ok - %s", name, method, string(content)) } } diff --git a/core/stores/mon/util_test.go b/core/stores/mon/util_test.go index 521a619c..be0c859e 100644 --- a/core/stores/mon/util_test.go +++ b/core/stores/mon/util_test.go @@ -42,18 +42,18 @@ func Test_logDuration(t *testing.T) { buf := logtest.NewCollector(t) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil) + logDuration(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil) assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "slow") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil) + logDuration(context.Background(), "foo", "bar", timex.Now(), nil) assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), errors.New("bar")) + logDuration(context.Background(), "foo", "bar", timex.Now(), errors.New("bar")) assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "fail") @@ -65,26 +65,26 @@ func Test_logDuration(t *testing.T) { buf.Reset() DisableInfoLog() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil) + logDuration(context.Background(), "foo", "bar", timex.Now(), nil) assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil) + logDuration(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil) assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "slow") buf.Reset() DisableLog() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil) + logDuration(context.Background(), "foo", "bar", timex.Now(), nil) assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil) + logDuration(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil) assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), errors.New("bar")) + logDuration(context.Background(), "foo", "bar", timex.Now(), errors.New("bar")) assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "fail") @@ -94,37 +94,37 @@ func Test_logDurationWithDoc(t *testing.T) { buf := logtest.NewCollector(t) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, make(chan int)) + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, make(chan int)) assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "slow") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, "{'json': ''}") + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, "{'json': ''}") assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "slow") assert.Contains(t, buf.String(), "json") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil, make(chan int)) + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now(), nil, make(chan int)) assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil, "{'json': ''}") + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now(), nil, "{'json': ''}") assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "json") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), errors.New("bar"), make(chan int)) + logDurationWithDocs(context.Background(), "foo", "bar", 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(), "fail") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), errors.New("bar"), "{'json': ''}") + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now(), errors.New("bar"), "{'json': ''}") assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "fail") @@ -137,21 +137,21 @@ func Test_logDurationWithDoc(t *testing.T) { buf.Reset() DisableInfoLog() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil, make(chan int)) + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now(), nil, make(chan int)) assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil, "{'json': ''}") + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now(), nil, "{'json': ''}") assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, make(chan int)) + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, make(chan int)) assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "slow") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, "{'json': ''}") + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, "{'json': ''}") assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "slow") @@ -159,29 +159,29 @@ func Test_logDurationWithDoc(t *testing.T) { buf.Reset() DisableLog() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil, make(chan int)) + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now(), nil, make(chan int)) assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), nil, "{'json': ''}") + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now(), nil, "{'json': ''}") assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, make(chan int)) + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, make(chan int)) assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, "{'json': ''}") + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now()-slowThreshold.Load()*2, nil, "{'json': ''}") assert.Empty(t, buf.String()) buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), errors.New("bar"), make(chan int)) + logDurationWithDocs(context.Background(), "foo", "bar", 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(), "fail") buf.Reset() - logDurationWithDoc(context.Background(), "foo", "bar", timex.Now(), errors.New("bar"), "{'json': ''}") + logDurationWithDocs(context.Background(), "foo", "bar", timex.Now(), errors.New("bar"), "{'json': ''}") assert.Contains(t, buf.String(), "foo") assert.Contains(t, buf.String(), "bar") assert.Contains(t, buf.String(), "fail")