logr/timeout_test.go at master · mattermost/logr · GitHub

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
package logr_test

import (
	"context"
	"errors"
	"testing"
	"time"

	"github.com/mattermost/logr/v2"
	"github.com/stretchr/testify/assert"
	"github.com/stretchr/testify/require"
	"github.com/wiggin77/merror"
)

func TestIsTimeoutError_Simple(t *testing.T) {
	// Regular error should return false
	regularErr := errors.New("regular error")
	assert.False(t, logr.IsTimeoutError(regularErr))

	// Nil error should return false
	assert.False(t, logr.IsTimeoutError(nil))
}

func TestIsTimeoutError_ActualTimeout(t *testing.T) {
	lgr, err := logr.New(
		logr.MaxQueueSize(1),
		logr.EnqueueTimeout(1), // 1 ms timeout
	)
	require.NoError(t, err)

	// Fill the queue
	logger := lgr.NewLogger()
	for i := 0; i < 100; i++ {
		logger.Info("message", logr.Int("i", i))
	}

	// Try to flush with a very short timeout - should timeout
	ctx, cancel := context.WithTimeout(context.Background(), 1*time.Millisecond)
	defer cancel()
	err = lgr.FlushWithTimeout(ctx)
	if err != nil {
		assert.True(t, logr.IsTimeoutError(err), "FlushWithTimeout error should be detectable as timeout")
	}

	// Clean up
	_ = lgr.Shutdown()
}

func TestIsTimeoutError_WithMError(t *testing.T) {
	merr := &merror.MError{}

	// MError without timeout errors
	merr.Append(errors.New("error 1"))
	merr.Append(errors.New("error 2"))
	assert.False(t, logr.IsTimeoutError(merr))

	// Create a new logger that will timeout
	lgr, err := logr.New(
		logr.MaxQueueSize(1),
		logr.EnqueueTimeout(1),
	)
	require.NoError(t, err)

	logger := lgr.NewLogger()
	for i := 0; i < 100; i++ {
		logger.Info("flood", logr.Int("i", i))
	}

	// Get a timeout error
	ctx, cancel := context.WithTimeout(context.Background(), 1*time.Millisecond)
	defer cancel()
	flushErr := lgr.FlushWithTimeout(ctx)

	// Create MError with timeout
	merr2 := &merror.MError{}
	merr2.Append(errors.New("other error"))
	if flushErr != nil {
		merr2.Append(flushErr)
		// Should detect timeout in multi-error
		assert.True(t, logr.IsTimeoutError(merr2), "Should detect timeout in MError")
	}

	_ = lgr.Shutdown()
}

func TestTimeoutError_ErrorMessage(t *testing.T) {
	lgr, err := logr.New(
		logr.MaxQueueSize(1),
		logr.EnqueueTimeout(1),
	)
	require.NoError(t, err)

	logger := lgr.NewLogger()
	for i := 0; i < 100; i++ {
		logger.Info("message", logr.Int("i", i))
	}

	ctx, cancel := context.WithTimeout(context.Background(), 1*time.Millisecond)
	defer cancel()
	err = lgr.FlushWithTimeout(ctx)
	if err != nil {
		assert.True(t, logr.IsTimeoutError(err))
		assert.Contains(t, err.Error(), "timeout", "Timeout error message should contain 'timeout'")
	}

	_ = lgr.Shutdown()
}

func TestShutdownTimeout_WithTimeout(t *testing.T) {
	// Create logger with very short shutdown timeout
	lgr, err := logr.New(
		logr.ShutdownTimeout(1), // 1 ms timeout
		logr.MaxQueueSize(1000),
	)
	require.NoError(t, err)

	// Fill queue with lots of messages
	logger := lgr.NewLogger()
	for i := 0; i < 1000; i++ {
		logger.Info("message", logr.Int("i", i))
	}

	// Shutdown with short timeout may produce timeout error
	err = lgr.Shutdown()
	// This may or may not timeout depending on system speed, but if it does,
	// it should be detectable as a timeout error
	if err != nil && logr.IsTimeoutError(err) {
		assert.Contains(t, err.Error(), "timeout")
	}
}

func TestFlushTimeout_Success(t *testing.T) {
	lgr, err := logr.New()
	require.NoError(t, err)
	defer func() { require.NoError(t, lgr.Shutdown()) }()

	logger := lgr.NewLogger()
	logger.Info("test message")

	// Flush with reasonable timeout should succeed
	ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
	defer cancel()
	err = lgr.FlushWithTimeout(ctx)
	assert.NoError(t, err, "Flush with reasonable timeout should not timeout")
	assert.False(t, logr.IsTimeoutError(err))
}