github.com/demonoid81/moby@v0.0.0-20200517203328-62dd8e17c460/daemon/logger/loggerutils/logfile_test.go (about) 1 package loggerutils 2 3 import ( 4 "bufio" 5 "context" 6 "io" 7 "io/ioutil" 8 "os" 9 "strings" 10 "testing" 11 "time" 12 13 "github.com/demonoid81/moby/daemon/logger" 14 "github.com/demonoid81/moby/pkg/pubsub" 15 "github.com/demonoid81/moby/pkg/tailfile" 16 "gotest.tools/v3/assert" 17 ) 18 19 type testDecoder struct { 20 rdr io.Reader 21 scanner *bufio.Scanner 22 } 23 24 func (d *testDecoder) Decode() (*logger.Message, error) { 25 if d.scanner == nil { 26 d.scanner = bufio.NewScanner(d.rdr) 27 } 28 if !d.scanner.Scan() { 29 return nil, d.scanner.Err() 30 } 31 // some comment 32 return &logger.Message{Line: d.scanner.Bytes(), Timestamp: time.Now()}, nil 33 } 34 35 func (d *testDecoder) Reset(rdr io.Reader) { 36 d.rdr = rdr 37 d.scanner = bufio.NewScanner(rdr) 38 } 39 40 func (d *testDecoder) Close() { 41 d.rdr = nil 42 d.scanner = nil 43 } 44 45 func TestTailFiles(t *testing.T) { 46 s1 := strings.NewReader("Hello.\nMy name is Inigo Montoya.\n") 47 s2 := strings.NewReader("I'm serious.\nDon't call me Shirley!\n") 48 s3 := strings.NewReader("Roads?\nWhere we're going we don't need roads.\n") 49 50 files := []SizeReaderAt{s1, s2, s3} 51 watcher := logger.NewLogWatcher() 52 53 tailReader := func(ctx context.Context, r SizeReaderAt, lines int) (io.Reader, int, error) { 54 return tailfile.NewTailReader(ctx, r, lines) 55 } 56 dec := &testDecoder{} 57 58 for desc, config := range map[string]logger.ReadConfig{} { 59 t.Run(desc, func(t *testing.T) { 60 started := make(chan struct{}) 61 go func() { 62 close(started) 63 tailFiles(files, watcher, dec, tailReader, config) 64 }() 65 <-started 66 }) 67 } 68 69 config := logger.ReadConfig{Tail: 2} 70 started := make(chan struct{}) 71 go func() { 72 close(started) 73 tailFiles(files, watcher, dec, tailReader, config) 74 }() 75 <-started 76 77 select { 78 case <-time.After(60 * time.Second): 79 t.Fatal("timeout waiting for tail line") 80 case err := <-watcher.Err: 81 assert.NilError(t, err) 82 case msg := <-watcher.Msg: 83 assert.Assert(t, msg != nil) 84 assert.Assert(t, string(msg.Line) == "Roads?", string(msg.Line)) 85 } 86 87 select { 88 case <-time.After(60 * time.Second): 89 t.Fatal("timeout waiting for tail line") 90 case err := <-watcher.Err: 91 assert.NilError(t, err) 92 case msg := <-watcher.Msg: 93 assert.Assert(t, msg != nil) 94 assert.Assert(t, string(msg.Line) == "Where we're going we don't need roads.", string(msg.Line)) 95 } 96 } 97 98 type dummyDecoder struct{} 99 100 func (dummyDecoder) Decode() (*logger.Message, error) { 101 return &logger.Message{}, nil 102 } 103 104 func (dummyDecoder) Close() {} 105 func (dummyDecoder) Reset(io.Reader) {} 106 107 func TestFollowLogsConsumerGone(t *testing.T) { 108 lw := logger.NewLogWatcher() 109 110 f, err := ioutil.TempFile("", t.Name()) 111 assert.NilError(t, err) 112 defer func() { 113 f.Close() 114 os.Remove(f.Name()) 115 }() 116 117 dec := dummyDecoder{} 118 119 followLogsDone := make(chan struct{}) 120 var since, until time.Time 121 go func() { 122 followLogs(f, lw, make(chan interface{}), dec, since, until) 123 close(followLogsDone) 124 }() 125 126 select { 127 case <-lw.Msg: 128 case err := <-lw.Err: 129 assert.NilError(t, err) 130 case <-followLogsDone: 131 t.Fatal("follow logs finished unexpectedly") 132 case <-time.After(10 * time.Second): 133 t.Fatal("timeout waiting for log message") 134 } 135 136 lw.ConsumerGone() 137 select { 138 case <-followLogsDone: 139 case <-time.After(20 * time.Second): 140 t.Fatal("timeout waiting for followLogs() to finish") 141 } 142 } 143 144 type dummyWrapper struct { 145 dummyDecoder 146 fn func() error 147 } 148 149 func (d *dummyWrapper) Decode() (*logger.Message, error) { 150 if err := d.fn(); err != nil { 151 return nil, err 152 } 153 return d.dummyDecoder.Decode() 154 } 155 156 func TestFollowLogsProducerGone(t *testing.T) { 157 lw := logger.NewLogWatcher() 158 159 f, err := ioutil.TempFile("", t.Name()) 160 assert.NilError(t, err) 161 defer os.Remove(f.Name()) 162 163 var sent, received, closed int 164 dec := &dummyWrapper{fn: func() error { 165 switch closed { 166 case 0: 167 sent++ 168 return nil 169 case 1: 170 closed++ 171 t.Logf("logDecode() closed after sending %d messages\n", sent) 172 return io.EOF 173 default: 174 t.Fatal("logDecode() called after closing!") 175 return io.EOF 176 } 177 }} 178 var since, until time.Time 179 180 followLogsDone := make(chan struct{}) 181 go func() { 182 followLogs(f, lw, make(chan interface{}), dec, since, until) 183 close(followLogsDone) 184 }() 185 186 // read 1 message 187 select { 188 case <-lw.Msg: 189 received++ 190 case err := <-lw.Err: 191 assert.NilError(t, err) 192 case <-followLogsDone: 193 t.Fatal("followLogs() finished unexpectedly") 194 case <-time.After(10 * time.Second): 195 t.Fatal("timeout waiting for log message") 196 } 197 198 // "stop" the "container" 199 closed = 1 200 lw.ProducerGone() 201 202 // should receive all the messages sent 203 readDone := make(chan struct{}) 204 go func() { 205 defer close(readDone) 206 for { 207 select { 208 case <-lw.Msg: 209 received++ 210 if received == sent { 211 return 212 } 213 case err := <-lw.Err: 214 assert.NilError(t, err) 215 } 216 } 217 }() 218 select { 219 case <-readDone: 220 case <-time.After(30 * time.Second): 221 t.Fatalf("timeout waiting for log messages to be read (sent: %d, received: %d", sent, received) 222 } 223 224 t.Logf("messages sent: %d, received: %d", sent, received) 225 226 // followLogs() should be done by now 227 select { 228 case <-followLogsDone: 229 case <-time.After(30 * time.Second): 230 t.Fatal("timeout waiting for followLogs() to finish") 231 } 232 233 select { 234 case <-lw.WatchConsumerGone(): 235 t.Fatal("consumer should not have exited") 236 default: 237 } 238 } 239 240 func TestCheckCapacityAndRotate(t *testing.T) { 241 dir, err := ioutil.TempDir("", t.Name()) 242 assert.NilError(t, err) 243 defer os.RemoveAll(dir) 244 245 f, err := ioutil.TempFile(dir, "log") 246 assert.NilError(t, err) 247 248 l := &LogFile{ 249 f: f, 250 capacity: 5, 251 maxFiles: 3, 252 compress: true, 253 notifyRotate: pubsub.NewPublisher(0, 1), 254 perms: 0600, 255 marshal: func(msg *logger.Message) ([]byte, error) { 256 return msg.Line, nil 257 }, 258 } 259 defer l.Close() 260 261 assert.NilError(t, l.WriteLogEntry(&logger.Message{Line: []byte("hello world!")})) 262 263 dStringer := dirStringer{dir} 264 265 _, err = os.Stat(f.Name() + ".1") 266 assert.Assert(t, os.IsNotExist(err), dStringer) 267 268 assert.NilError(t, l.WriteLogEntry(&logger.Message{Line: []byte("hello world!")})) 269 _, err = os.Stat(f.Name() + ".1") 270 assert.NilError(t, err, dStringer) 271 272 assert.NilError(t, l.WriteLogEntry(&logger.Message{Line: []byte("hello world!")})) 273 _, err = os.Stat(f.Name() + ".1") 274 assert.NilError(t, err, dStringer) 275 _, err = os.Stat(f.Name() + ".2.gz") 276 assert.NilError(t, err, dStringer) 277 278 // Now let's simulate a failed rotation where the file was able to be closed but something else happened elsewhere 279 // down the line. 280 // We want to make sure that we can recover in the case that `l.f` was closed while attempting a rotation. 281 l.f.Close() 282 assert.NilError(t, l.WriteLogEntry(&logger.Message{Line: []byte("hello world!")})) 283 } 284 285 type dirStringer struct { 286 d string 287 } 288 289 func (d dirStringer) String() string { 290 ls, err := ioutil.ReadDir(d.d) 291 if err != nil { 292 return "" 293 } 294 var s strings.Builder 295 s.WriteString("\n") 296 297 for _, fi := range ls { 298 s.WriteString(fi.Name() + "\n") 299 } 300 return s.String() 301 }