Line data Source code
1 : // Copyright 2019 The LevelDB-Go and Pebble Authors. All rights reserved. Use
2 : // of this source code is governed by a BSD-style license that can be found in
3 : // the LICENSE file.
4 :
5 : package metamorphic
6 :
7 : import (
8 : "fmt"
9 : "io"
10 : "log"
11 : "os"
12 : "regexp"
13 : "strconv"
14 : "strings"
15 : "sync"
16 : "sync/atomic"
17 : "time"
18 : "unicode"
19 :
20 : "github.com/cockroachdb/errors"
21 : "github.com/pmezard/go-difflib/difflib"
22 : "github.com/stretchr/testify/require"
23 : )
24 :
25 : // history records the results of running a series of operations.
26 : //
27 : // history also implements the pebble.Logger interface, outputting to a stdlib
28 : // logger, prefixing the log messages with "//"-style comments.
29 : type history struct {
30 : err atomic.Value
31 : failRE *regexp.Regexp
32 : log *log.Logger
33 : mu struct {
34 : sync.Mutex
35 : closed bool
36 : }
37 : }
38 :
39 2 : func newHistory(failRE *regexp.Regexp, writers ...io.Writer) *history {
40 2 : h := &history{failRE: failRE}
41 2 : h.log = log.New(io.MultiWriter(writers...), "", 0)
42 2 : return h
43 2 : }
44 :
45 2 : func (h *history) Close() {
46 2 : h.mu.Lock()
47 2 : h.mu.closed = true
48 2 : h.mu.Unlock()
49 2 : }
50 :
51 2 : func (h *history) Recordf(op int, format string, args ...interface{}) {
52 2 : h.mu.Lock()
53 2 : defer h.mu.Unlock()
54 2 : if h.mu.closed {
55 0 : panic("Recordf after close")
56 : }
57 2 : if strings.Contains(format, "\n") {
58 0 : // We could remove this restriction but suffixing every line with "#<seq>".
59 0 : panic(fmt.Sprintf("format string must not contain \\n: %q", format))
60 : }
61 :
62 : // We suffix every line with #<op> in order to provide a marker to locate
63 : // the line using the diff output. This is necessary because the diff of two
64 : // histories is done after stripping comment lines (`// ...`) from the
65 : // history output, which ruins the line number information in the diff
66 : // output.
67 2 : m := fmt.Sprintf(format, args...) + fmt.Sprintf(" #%d", op)
68 2 : h.log.Print(m)
69 2 :
70 2 : if h.failRE != nil && h.failRE.MatchString(m) {
71 1 : err := errors.Errorf("failure regexp %q matched output: %s", h.failRE, m)
72 1 : h.err.Store(err)
73 1 : }
74 : }
75 :
76 : // Error returns an error if the test has failed from log output, either a
77 : // failure regexp match or a call to Fatalf.
78 2 : func (h *history) Error() error {
79 2 : if v := h.err.Load(); v != nil {
80 1 : return v.(error)
81 1 : }
82 2 : return nil
83 : }
84 :
85 2 : func (h *history) format(typ, format string, args ...interface{}) string {
86 2 : var buf strings.Builder
87 2 : orig := fmt.Sprintf(format, args...)
88 2 : timestamp := time.Now().Format("15:04:05.000")
89 2 : for _, line := range strings.Split(strings.TrimSpace(orig), "\n") {
90 2 : fmt.Fprintf(&buf, "// %s %s: %s\n", timestamp, typ, line)
91 2 : }
92 2 : return buf.String()
93 : }
94 :
95 : // Infof implements the pebble.Logger interface. Note that the output is
96 : // commented.
97 2 : func (h *history) Infof(format string, args ...interface{}) {
98 2 : h.mu.Lock()
99 2 : defer h.mu.Unlock()
100 2 : // Suppress any messages that come after closing. This could happen if the
101 2 : // test doesn't close the database.
102 2 : if !h.mu.closed {
103 2 : _ = h.log.Output(2, h.format("INFO", format, args...))
104 2 : }
105 : }
106 :
107 : // Errorf implements the pebble.Logger interface. Note that the output is
108 : // commented.
109 0 : func (h *history) Errorf(format string, args ...interface{}) {
110 0 : h.mu.Lock()
111 0 : defer h.mu.Unlock()
112 0 : // Suppress any messages that come after closing. This could happen if the
113 0 : // test doesn't close the database.
114 0 : if !h.mu.closed {
115 0 : _ = h.log.Output(2, h.format("ERROR", format, args...))
116 0 : }
117 : }
118 :
119 : // Fatalf implements the pebble.Logger interface. Note that the output is
120 : // commented.
121 1 : func (h *history) Fatalf(format string, args ...interface{}) {
122 1 : h.mu.Lock()
123 1 : defer h.mu.Unlock()
124 1 : if h.mu.closed {
125 0 : panic(fmt.Sprintf(format, args...))
126 : }
127 1 : _ = h.log.Output(2, h.format("FATAL", format, args...))
128 1 : // Store the first fatal error message.
129 1 : h.err.CompareAndSwap(nil, errors.Errorf(format, args...))
130 : }
131 :
132 : func (h *history) recorder(
133 : thread int, op int, optionalRecordf func(format string, args ...interface{}),
134 2 : ) historyRecorder {
135 2 : return historyRecorder{
136 2 : history: h,
137 2 : op: op,
138 2 : optionalRecordf: optionalRecordf,
139 2 : }
140 2 : }
141 :
142 : // historyRecorder pairs a history with an operation, annotating all lines
143 : // recorded through it with the operation number.
144 : type historyRecorder struct {
145 : history *history
146 : op int
147 : optionalRecordf func(string, ...interface{})
148 : }
149 :
150 : // Recordf records the results of a single operation.
151 2 : func (h historyRecorder) Recordf(format string, args ...interface{}) {
152 2 : // Check for assertion errors.
153 2 : for _, a := range args {
154 2 : if err, ok := a.(error); ok && errors.IsAssertionFailure(err) {
155 0 : fmt.Fprintf(os.Stderr, "%+v", err)
156 0 : panic(err)
157 : }
158 : }
159 2 : h.history.Recordf(h.op, format, args...)
160 2 : // If the history recorder was configured with an additional record func,
161 2 : // invoke it. This can be used to collect the per-operation output when
162 2 : // manually stepping the metamorphic test.
163 2 : if h.optionalRecordf != nil {
164 1 : h.optionalRecordf(format, args...)
165 1 : }
166 : }
167 :
168 : // Error returns an error if the test has failed from log output, either a
169 : // failure regexp match or a call to Fatalf.
170 0 : func (h historyRecorder) Error() error {
171 0 : return h.history.Error()
172 0 : }
173 :
174 : // CompareHistories takes a slice of file paths containing history files. It
175 : // performs a diff comparing the first path to all other paths. CompareHistories
176 : // returns the index and diff for the first history that differs. If all the
177 : // histories are identical, CompareHistories returns a zero index and an empty
178 : // string.
179 0 : func CompareHistories(t TestingT, paths []string) (i int, diff string) {
180 0 : base := readHistory(t, paths[0])
181 0 : base = reorderHistory(base)
182 0 :
183 0 : for i := 1; i < len(paths); i++ {
184 0 : lines := readHistory(t, paths[i])
185 0 : lines = reorderHistory(lines)
186 0 : diff := difflib.UnifiedDiff{
187 0 : A: base,
188 0 : B: lines,
189 0 : Context: 5,
190 0 : }
191 0 : text, err := difflib.GetUnifiedDiffString(diff)
192 0 : require.NoError(t, err)
193 0 : if text != "" {
194 0 : return i, text
195 0 : }
196 : }
197 0 : return 0, ""
198 : }
199 :
200 : // reorderHistory takes lines from a history file and reorders the operation
201 : // results to be in the order of the operation index numbers. Runs with more
202 : // than 1 thread may produce out-of-order histories. Comment lines must've
203 : // already been filtered out.
204 1 : func reorderHistory(lines []string) []string {
205 1 : reordered := make([]string, len(lines))
206 1 : for _, l := range lines {
207 1 : if cleaned := strings.TrimSpace(l); cleaned == "" {
208 1 : continue
209 : }
210 1 : idx := extractOp(l)
211 1 : if idx >= len(reordered) {
212 0 : panic("incomplete test history; this shouldn't happen given that execution completed successfully")
213 : }
214 1 : reordered[idx] = l
215 : }
216 1 : return reordered
217 : }
218 :
219 : // extractOp parses out an operation's index from the trailing comment. Every
220 : // line of history output is suffixed with a comment containing `#<op>`
221 1 : func extractOp(line string) int {
222 1 : i := strings.LastIndexByte(line, '#')
223 1 : j := strings.IndexFunc(line[i+1:], unicode.IsSpace)
224 1 : if j == -1 {
225 0 : j = len(line[i+1:])
226 0 : }
227 1 : v, err := strconv.Atoi(line[i+1 : i+1+j])
228 1 : if err != nil {
229 0 : panic(fmt.Sprintf("unable to parse line %q: %s", line, err))
230 : }
231 1 : return v
232 : }
233 :
234 : // Read a history file, stripping out lines that begin with a comment.
235 1 : func readHistory(t TestingT, historyPath string) []string {
236 1 : data, err := os.ReadFile(historyPath)
237 1 : require.NoError(t, err)
238 1 : lines := difflib.SplitLines(string(data))
239 1 : newLines := make([]string, 0, len(lines))
240 1 : for _, line := range lines {
241 1 : if strings.HasPrefix(line, "// ") {
242 1 : continue
243 : }
244 1 : newLines = append(newLines, line)
245 : }
246 1 : return newLines
247 : }
|
