Repository: zeromicro/go-zero
Pull request #3606 (2023-10-08 06:36:23)

feat: support for disable mon logs like sqlx
1. Call mon.DisableLog to disable info and slow logs
2. Call mon.DisableInfoLog to disable info logs

codecov[bot]: ## [Codecov](https://app.codecov.io/gh/zeromicro/go-zero/pull/3606?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=None) Report
> Merging [#3606](https://app.codecov.io/gh/zeromicro/go-zero/pull/3606?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=None) (792169d) into [master](https://app.codecov.io/gh/zeromicro/go-zero/commit/ff230c4b1d9c165f1aefdee278c25980288733c2?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=None) (ff230c4) will **decrease** coverage by `0.02%`.
> The diff coverage is `100.00%`.


| [Files](https://app.codecov.io/gh/zeromicro/go-zero/pull/3606?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=None) | Coverage Δ | |
|---|---|---|
| [core/stores/mon/collection.go](https://app.codecov.io/gh/zeromicro/go-zero/pull/3606?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=None#diff-Y29yZS9zdG9yZXMvbW9uL2NvbGxlY3Rpb24uZ28=) | `100.00% <100.00%> (ø)` | |
| [core/stores/mon/options.go](https://app.codecov.io/gh/zeromicro/go-zero/pull/3606?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=None#diff-Y29yZS9zdG9yZXMvbW9uL29wdGlvbnMuZ28=) | `100.00% <100.00%> (ø)` | |
| [core/stores/mon/util.go](https://app.codecov.io/gh/zeromicro/go-zero/pull/3606?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=None#diff-Y29yZS9zdG9yZXMvbW9uL3V0aWwuZ28=) | `100.00% <100.00%> (ø)` | |

... and [1 file with indirect coverage changes](https://app.codecov.io/gh/zeromicro/go-zero/pull/3606/indirect-changes?src=pr&el=tree-more&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=None)


Patch:
diff --git a/core/stores/mon/collection.go b/core/stores/mon/collection.go
index e052dcc7..669d43f5 100644
--- a/core/stores/mon/collection.go
+++ b/core/stores/mon/collection.go
@@ -2,12 +2,10 @@ package mon
 
 import (
 	"context"
-	"encoding/json"
 	"errors"
 	"time"
 
 	"github.com/zeromicro/go-zero/core/breaker"
-	"github.com/zeromicro/go-zero/core/logx"
 	"github.com/zeromicro/go-zero/core/timex"
 	"go.mongodb.org/mongo-driver/mongo"
 	mopt "go.mongodb.org/mongo-driver/mongo/options"
@@ -503,42 +501,7 @@ 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) {
-	duration := timex.Since(startTime)
-	logger := logx.WithContext(ctx).WithDuration(duration)
-
-	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 {
-			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 {
-		if duration > slowThreshold.Load() {
-			logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - fail(%s) - %s",
-				c.name, method, err.Error(), string(content))
-		} else {
-			logger.Infof("mongo(%s) - %s - fail(%s) - %s",
-				c.name, method, err.Error(), string(content))
-		}
-	} else {
-		if duration > slowThreshold.Load() {
-			logger.Slowf("[MONGO] mongo(%s) - slowcall - %s - ok - %s",
-				c.name, method, string(content))
-		} else {
-			logger.Infof("mongo(%s) - %s - ok - %s", c.name, method, string(content))
-		}
-	}
+	logDurationWithDoc(ctx, c.name, method, startTime, err, docs...)
 }
 
 func (c *decoratedCollection) logDurationSimple(ctx context.Context, method string, startTime time.Duration, err error) {
diff --git a/core/stores/mon/options.go b/core/stores/mon/options.go
index ca13bff8..9ce06ad6 100644
--- a/core/stores/mon/options.go
+++ b/core/stores/mon/options.go
@@ -9,7 +9,11 @@ import (
 
 const defaultTimeout = time.Second * 3
 
-var slowThreshold = syncx.ForAtomicDuration(defaultSlowThreshold)
+var (
+	slowThreshold = syncx.ForAtomicDuration(defaultSlowThreshold)
+	logMon        = syncx.ForAtomicBool(true)
+	logSlowMon    = syncx.ForAtomicBool(true)
+)
 
 type (
 	options = mopt.ClientOptions
@@ -18,6 +22,17 @@ type (
 	Option func(opts *options)
 )
 
+// DisableLog disables logging of mongo command, includes info and slow logs.
+func DisableLog() {
+	logMon.Set(false)
+	logSlowMon.Set(false)
+}
+
+// DisableInfoLog disables info logging of mongo command, but keeps slow logs.
+func DisableInfoLog() {
+	logMon.Set(false)
+}
+
 // SetSlowThreshold sets the slow threshold.
 func SetSlowThreshold(threshold time.Duration) {
 	slowThreshold.Set(threshold)
diff --git a/core/stores/mon/util.go b/core/stores/mon/util.go
index e401df31..43f0ac3e 100644
--- a/core/stores/mon/util.go
+++ b/core/stores/mon/util.go
@@ -2,6 +2,8 @@ package mon
 
 import (
 	"context"
+	"encoding/json"
+	"errors"
 	"strings"
 	"time"
 
@@ -11,17 +13,53 @@ 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)
+}
+
+func logDurationWithDoc(ctx context.Context, name, method string,
+	startTime time.Duration, err error, docs ...any) {
 	duration := timex.Since(startTime)
 	logger := logx.WithContext(ctx).WithDuration(duration)
-	if err != nil {
-		logger.Infof("mongo(%s) - %s - fail(%s)", name, method, err.Error())
+	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))
+			}
+		}
+
+		return
+	}
+
+	if jerr != nil {
+		logger.Errorf("mongo(%s) - %s - fail(%s)", name, method, err.Error())
 	} else {
-		logger.Infof("mongo(%s) - %s - ok", name, method)
+		logger.Errorf("mongo(%s) - %s - fail(%s) - %s",
+			name, method, err.Error(), string(content))
 	}
 }


Test patch:
diff --git a/core/stores/mon/collection_test.go b/core/stores/mon/collection_test.go
index 964ebb23..95402c63 100644
--- a/core/stores/mon/collection_test.go
+++ b/core/stores/mon/collection_test.go
@@ -599,13 +599,11 @@ func TestDecoratedCollection_LogDuration(t *testing.T) {
 		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(), "slowcall")
 
 	buf.Reset()
 	c.logDuration(context.Background(), "foo", timex.Now()-slowThreshold.Load()*2, nil)
diff --git a/core/stores/mon/options_test.go b/core/stores/mon/options_test.go
index 5582f492..ee944f94 100644
--- a/core/stores/mon/options_test.go
+++ b/core/stores/mon/options_test.go
@@ -25,3 +25,29 @@ func TestWithTimeout(t *testing.T) {
 	WithTimeout(time.Second)(opts)
 	assert.Equal(t, time.Second, *opts.Timeout)
 }
+
+func TestDisableLog(t *testing.T) {
+	assert.True(t, logMon.True())
+	assert.True(t, logSlowMon.True())
+	defer func() {
+		logMon.Set(true)
+		logSlowMon.Set(true)
+	}()
+
+	DisableLog()
+	assert.False(t, logMon.True())
+	assert.False(t, logSlowMon.True())
+}
+
+func TestDisableInfoLog(t *testing.T) {
+	assert.True(t, logMon.True())
+	assert.True(t, logSlowMon.True())
+	defer func() {
+		logMon.Set(true)
+		logSlowMon.Set(true)
+	}()
+
+	DisableInfoLog()
+	assert.False(t, logMon.True())
+	assert.True(t, logSlowMon.True())
+}
diff --git a/core/stores/mon/util_test.go b/core/stores/mon/util_test.go
index 3ab7cf2b..521a619c 100644
--- a/core/stores/mon/util_test.go
+++ b/core/stores/mon/util_test.go
@@ -4,10 +4,10 @@ import (
 	"context"
 	"errors"
 	"testing"
-	"time"
 
 	"github.com/stretchr/testify/assert"
 	"github.com/zeromicro/go-zero/core/logx/logtest"
+	"github.com/zeromicro/go-zero/core/timex"
 )
 
 func TestFormatAddrs(t *testing.T) {
@@ -42,13 +42,148 @@ func Test_logDuration(t *testing.T) {
 	buf := logtest.NewCollector(t)
 
 	buf.Reset()
-	logDuration(context.Background(), "foo", "bar", time.Millisecond, nil)
+	logDurationWithDoc(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()
-	logDuration(context.Background(), "foo", "bar", time.Millisecond, errors.New("bar"))
+	logDurationWithDoc(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"))
+	assert.Contains(t, buf.String(), "foo")
+	assert.Contains(t, buf.String(), "bar")
+	assert.Contains(t, buf.String(), "fail")
+
+	defer func() {
+		logMon.Set(true)
+		logSlowMon.Set(true)
+	}()
+
+	buf.Reset()
+	DisableInfoLog()
+	logDurationWithDoc(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)
+	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)
+	assert.Empty(t, buf.String())
+
+	buf.Reset()
+	logDurationWithDoc(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"))
+	assert.Contains(t, buf.String(), "foo")
+	assert.Contains(t, buf.String(), "bar")
+	assert.Contains(t, buf.String(), "fail")
+}
+
+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))
+	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': ''}")
+	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))
+	assert.Contains(t, buf.String(), "foo")
+	assert.Contains(t, buf.String(), "bar")
+
+	buf.Reset()
+	logDurationWithDoc(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))
+	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': ''}")
+	assert.Contains(t, buf.String(), "foo")
+	assert.Contains(t, buf.String(), "bar")
+	assert.Contains(t, buf.String(), "fail")
+	assert.Contains(t, buf.String(), "json")
+
+	defer func() {
+		logMon.Set(true)
+		logSlowMon.Set(true)
+	}()
+
+	buf.Reset()
+	DisableInfoLog()
+	logDurationWithDoc(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': ''}")
+	assert.Empty(t, buf.String())
+
+	buf.Reset()
+	logDurationWithDoc(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': ''}")
+	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()
+	DisableLog()
+	logDurationWithDoc(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': ''}")
+	assert.Empty(t, buf.String())
+
+	buf.Reset()
+	logDurationWithDoc(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': ''}")
+	assert.Empty(t, buf.String())
+
+	buf.Reset()
+	logDurationWithDoc(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': ''}")
 	assert.Contains(t, buf.String(), "foo")
 	assert.Contains(t, buf.String(), "bar")
 	assert.Contains(t, buf.String(), "fail")
+	assert.Contains(t, buf.String(), "json")
 }