Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

add non-block write log in asynchronous mode #5150

Merged
merged 2 commits into from
Feb 7, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
# developing
- [add non-block write log in asynchronous mode](https://github.com/beego/beego/pull/5150)
- [Fix 5126: support bloom filter cache](https://github.com/beego/beego/pull/5126)
- [Fix 5117: support write though cache](https://github.com/beego/beego/pull/5117)
- [add read through for cache module](https://github.com/beego/beego/pull/5116)
Expand Down
25 changes: 23 additions & 2 deletions core/logs/log.go
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,6 @@
// log.Warn("warning")
// log.Debug("debug")
// log.Critical("critical")
//
package logs

import (
Expand Down Expand Up @@ -115,6 +114,9 @@ type BeeLogger struct {
enableFuncCallDepth bool
enableFullFilePath bool
asynchronous bool
// Whether to discard logs when buffer is full and asynchronous is true
// No discard by default
logWithNonBlocking bool
wg sync.WaitGroup
level int
loggerFuncCallDepth int
Expand Down Expand Up @@ -175,6 +177,16 @@ func (bl *BeeLogger) Async(msgLen ...int64) *BeeLogger {
return bl
}

// AsyncNonBlockWrite Non-blocking write in asynchronous mode
// Only works if asynchronous write logging is set
func (bl *BeeLogger) AsyncNonBlockWrite() *BeeLogger {
if !bl.asynchronous {
return bl
}
bl.logWithNonBlocking = true
return bl
}

// SetLogger provides a given logger adapter into BeeLogger with config string.
// config must in in JSON format like {"interval":360}}
func (bl *BeeLogger) setLogger(adapterName string, configs ...string) error {
Expand Down Expand Up @@ -312,8 +324,17 @@ func (bl *BeeLogger) writeMsg(lm *LogMsg) error {
logM.FilePath = lm.FilePath
logM.LineNumber = lm.LineNumber
logM.Prefix = lm.Prefix

if bl.outputs != nil {
bl.msgChan <- lm
if bl.logWithNonBlocking {
select {
case bl.msgChan <- lm:
// discard log when channel is full
default:
}
} else {
bl.msgChan <- lm
}
} else {
logMsgPool.Put(lm)
}
Expand Down
96 changes: 96 additions & 0 deletions core/logs/log_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,11 @@
package logs

import (
"encoding/json"
"fmt"
"io"
"testing"
"time"

"github.com/stretchr/testify/assert"
)
Expand All @@ -30,3 +34,95 @@ func TestBeeLoggerDelLogger(t *testing.T) {
SetPrefix("aaa")
Info("hello")
}

type mockLogger struct {
*logWriter
WriteCost time.Duration `json:"write_cost"` // Simulated log writing time consuming
writeCnt int // Count add 1 when writing log success, just for test result
}

func NewMockLogger() Logger {
return &mockLogger{
logWriter: &logWriter{writer: io.Discard},
}
}

func (m *mockLogger) Init(config string) error {
return json.Unmarshal([]byte(config), m)
}

func (m *mockLogger) WriteMsg(lm *LogMsg) error {
m.Lock()
msg := lm.Msg
msg += "\n"

time.Sleep(m.WriteCost)
if _, err := m.writer.Write([]byte(msg)); err != nil {
return err
}

m.writeCnt++
m.Unlock()
return nil
}

func (m *mockLogger) GetCnt() int {
return m.writeCnt
}

func (*mockLogger) Destroy() {}
func (*mockLogger) Flush() {}
func (*mockLogger) SetFormatter(_ LogFormatter) {}

func TestBeeLogger_AsyncNonBlockWrite(t *testing.T) {
testCases := []struct {
name string
before func()
after func()
msgLen int64
writeCost time.Duration
sendInterval time.Duration
writeCnt int
}{
{
// Write log time is less than send log time, no blocking
name: "mock1",
after: func() {
_ = beeLogger.DelLogger("mock1")
},
msgLen: 5,
writeCnt: 10,
writeCost: 200 * time.Millisecond,
sendInterval: 300 * time.Millisecond,
},
{
// Write log time is less than send log time, discarded when blocking
name: "mock2",
after: func() {
_ = beeLogger.DelLogger("mock2")
},
writeCnt: 5,
msgLen: 5,
writeCost: 200 * time.Millisecond,
sendInterval: 10 * time.Millisecond,
},
}
for _, tc := range testCases {
t.Run(tc.name, func(t *testing.T) {
Register(tc.name, NewMockLogger)
err := beeLogger.SetLogger(tc.name, fmt.Sprintf(`{"write_cost": %d}`, tc.writeCost))
assert.Nil(t, err)

l := beeLogger.Async(tc.msgLen)
l.AsyncNonBlockWrite()

for i := 0; i < 10; i++ {
time.Sleep(tc.sendInterval)
l.Info(fmt.Sprintf("----%d----", i))
}
time.Sleep(1 * time.Second)
assert.Equal(t, tc.writeCnt, l.outputs[0].Logger.(*mockLogger).writeCnt)
tc.after()
})
}
}