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
|
package integrationtests
import (
"context"
"fmt"
"os"
"testing"
"time"
"github.com/mimecast/dtail/internal/config"
)
// TestDTailTimeoutExits guards the client-side --timeout deadline for the dtail
// follow client (task xu0). Historically the server-side read deadline fired at
// N seconds, but in tail+query streaming mode the session stayed alive via the
// map/aggregate command, so the client treated the closed read as a transient
// drop and auto-reconnected for another N-second cycle indefinitely - the
// process never exited. Plain "dtail --timeout N" (no --query) never emitted the
// timeout at all. Both are now covered by a client-side context deadline in
// cmd/dtail/main.go: whichever of --timeout / --shutdownAfter elapses first
// cancels the client context, so client.Start returns and the process exits.
//
// The assertion is that dtail exits well within a generous guard window. Without
// the fix the reconnect loop keeps the process alive past the guard, failing the
// test.
func TestDTailTimeoutExits(t *testing.T) {
testLogger := NewTestLogger("TestDTailTimeoutExits")
defer testLogger.WriteLogFile()
cleanupTmpFiles(t)
if !config.Env("DTAIL_INTEGRATION_TEST_RUN_MODE") {
t.Log("Skipping")
return
}
t.Run("QueryTimeoutExits", func(t *testing.T) {
runDTailTimeoutCase(t, testLogger, "dtail.timeout.query.tmp",
[]string{"--query", "select count($line) as cnt from STATS"})
})
t.Run("PlainTimeoutExits", func(t *testing.T) {
runDTailTimeoutCase(t, testLogger, "dtail.timeout.plain.tmp", nil)
})
}
// runDTailTimeoutCase starts a dserver, follows a growing file with
// "dtail --timeout <timeoutSeconds>" (plus any extra args), and asserts the
// client process exits within guardSeconds. The timeout is short relative to the
// guard so a regression (reconnect-after-timeout hang or a silently ignored
// --timeout) is caught by the guard firing first.
func runDTailTimeoutCase(t *testing.T, testLogger *TestLogger, followFile string, extraArgs []string) {
const (
timeoutSeconds = 3
guardSeconds = 20
)
port := getUniquePortNumber()
bindAddress := "localhost"
ctx, cancel := context.WithCancel(context.Background())
ctx = WithTestLogger(ctx, testLogger)
defer cancel()
if err := startTestServer(ctx, t, &ServerConfig{
Port: port,
BindAddress: bindAddress,
LogLevel: "error",
}); err != nil {
t.Fatalf("unable to start dserver: %v", err)
}
// Keep the file growing so the follow stays active (and would keep
// reconnecting without the client-side deadline) until the timeout fires.
fd, err := os.Create(followFile)
if err != nil {
t.Fatalf("unable to create follow file: %v", err)
}
defer func() {
_ = fd.Close()
_ = os.Remove(followFile)
}()
go func() {
for i := 0; ; i++ {
select {
case <-time.After(200 * time.Millisecond):
_, _ = fd.WriteString(fmt.Sprintf("%s Hello line %d\n", time.Now(), i))
case <-ctx.Done():
return
}
}
}()
args := []string{
"--cfg", "none",
"--logger", "stdout",
"--logLevel", "error",
"--servers", fmt.Sprintf("%s:%d", bindAddress, port),
"--files", followFile,
"--timeout", fmt.Sprintf("%d", timeoutSeconds),
"--trustAllHosts",
"--noColor",
}
args = append(args, extraArgs...)
start := time.Now()
stdoutCh, stderrCh, cmdErrCh, err := startCommand(ctx, t, "", "../dtail", args...)
if err != nil {
t.Fatalf("unable to start dtail: %v", err)
}
guard := time.NewTimer(guardSeconds * time.Second)
defer guard.Stop()
for {
select {
case line, ok := <-stdoutCh:
if ok {
t.Log("client stdout:", line)
}
case line, ok := <-stderrCh:
if ok {
t.Log("client stderr:", line)
}
case cmdErr := <-cmdErrCh:
elapsed := time.Since(start)
t.Logf("dtail exited after %s (err=%v)", elapsed, cmdErr)
if elapsed > guardSeconds*time.Second {
t.Fatalf("dtail exited after %s, expected well within %ds", elapsed, guardSeconds)
}
return
case <-guard.C:
t.Fatalf("dtail did not exit within %ds after --timeout %ds; "+
"likely reconnecting after the timeout-induced disconnect",
guardSeconds, timeoutSeconds)
}
}
}
|
