github.com/TheSilentForest/tail@v1.0.1-0.20190327153203-b5d4c85e68b5/tail_test.go (about) 1 // Copyright (c) 2015 HPE Software Inc. All rights reserved. 2 // Copyright (c) 2013 ActiveState Software Inc. All rights reserved. 3 4 // TODO: 5 // * repeat all the tests with Poll:true 6 7 package tail 8 9 import ( 10 "io/ioutil" 11 "os" 12 "strings" 13 "testing" 14 "time" 15 16 "github.com/TheSilentForest/tail/ratelimiter" 17 "github.com/TheSilentForest/tail/watch" 18 ) 19 20 func init() { 21 // Clear the temporary test directory 22 err := os.RemoveAll(".test") 23 if err != nil { 24 panic(err) 25 } 26 } 27 28 func TestMain(m *testing.M) { 29 // Use a smaller poll duration for faster test runs. Keep it below 30 // 100ms (which value is used as common delays for tests) 31 watch.POLL_DURATION = 5 * time.Millisecond 32 os.Exit(m.Run()) 33 } 34 35 func TestMustExist(t *testing.T) { 36 tail, err := TailFile("/no/such/file", Config{Follow: true, MustExist: true}) 37 if err == nil { 38 t.Error("MustExist:true is violated") 39 tail.Stop() 40 } 41 tail, err = TailFile("/no/such/file", Config{Follow: true, MustExist: false}) 42 if err != nil { 43 t.Error("MustExist:false is violated") 44 } 45 tail.Stop() 46 _, err = TailFile("README.md", Config{Follow: true, MustExist: true}) 47 if err != nil { 48 t.Error("MustExist:true on an existing file is violated") 49 } 50 tail.Cleanup() 51 } 52 53 func TestWaitsForFileToExist(t *testing.T) { 54 tailTest := NewTailTest("waits-for-file-to-exist", t) 55 tail := tailTest.StartTail("test.txt", Config{}) 56 go tailTest.VerifyTailOutput(tail, []string{"hello", "world"}, false) 57 58 <-time.After(100 * time.Millisecond) 59 tailTest.CreateFile("test.txt", "hello\nworld\n") 60 tailTest.Cleanup(tail, true) 61 } 62 63 func TestWaitsForFileToExistRelativePath(t *testing.T) { 64 tailTest := NewTailTest("waits-for-file-to-exist-relative", t) 65 66 oldWD, err := os.Getwd() 67 if err != nil { 68 tailTest.Fatal(err) 69 } 70 os.Chdir(tailTest.path) 71 defer os.Chdir(oldWD) 72 73 tail, err := TailFile("test.txt", Config{}) 74 if err != nil { 75 tailTest.Fatal(err) 76 } 77 78 go tailTest.VerifyTailOutput(tail, []string{"hello", "world"}, false) 79 80 <-time.After(100 * time.Millisecond) 81 if err := ioutil.WriteFile("test.txt", []byte("hello\nworld\n"), 0600); err != nil { 82 tailTest.Fatal(err) 83 } 84 tailTest.Cleanup(tail, true) 85 } 86 87 func TestStop(t *testing.T) { 88 tail, err := TailFile("_no_such_file", Config{Follow: true, MustExist: false}) 89 if err != nil { 90 t.Error("MustExist:false is violated") 91 } 92 if tail.Stop() != nil { 93 t.Error("Should be stoped successfully") 94 } 95 tail.Cleanup() 96 } 97 98 func TestStopAtEOF(t *testing.T) { 99 tailTest := NewTailTest("maxlinesize", t) 100 tailTest.CreateFile("test.txt", "hello\nthere\nworld\n") 101 tail := tailTest.StartTail("test.txt", Config{Follow: true, Location: nil}) 102 103 // read "hello" 104 line := <-tail.Lines 105 if line.Text != "hello" { 106 t.Errorf("Expected to get 'hello', got '%s' instead", line.Text) 107 } 108 109 tailTest.VerifyTailOutput(tail, []string{"there", "world"}, false) 110 tail.StopAtEOF() 111 tailTest.Cleanup(tail, true) 112 } 113 114 func TestMaxLineSizeFollow(t *testing.T) { 115 // As last file line does not end with newline, it will not be present in tail's output 116 maxLineSize(t, true, "hello\nworld\nfin\nhe", []string{"hel", "lo", "wor", "ld", "fin"}) 117 } 118 119 func TestMaxLineSizeNoFollow(t *testing.T) { 120 maxLineSize(t, false, "hello\nworld\nfin\nhe", []string{"hel", "lo", "wor", "ld", "fin", "he"}) 121 } 122 123 func TestOver4096ByteLine(t *testing.T) { 124 tailTest := NewTailTest("Over4096ByteLine", t) 125 testString := strings.Repeat("a", 4097) 126 tailTest.CreateFile("test.txt", "test\n"+testString+"\nhello\nworld\n") 127 tail := tailTest.StartTail("test.txt", Config{Follow: true, Location: nil}) 128 go tailTest.VerifyTailOutput(tail, []string{"test", testString, "hello", "world"}, false) 129 130 // Delete after a reasonable delay, to give tail sufficient time 131 // to read all lines. 132 <-time.After(100 * time.Millisecond) 133 tailTest.RemoveFile("test.txt") 134 tailTest.Cleanup(tail, true) 135 } 136 func TestOver4096ByteLineWithSetMaxLineSize(t *testing.T) { 137 tailTest := NewTailTest("Over4096ByteLineMaxLineSize", t) 138 testString := strings.Repeat("a", 4097) 139 tailTest.CreateFile("test.txt", "test\n"+testString+"\nhello\nworld\n") 140 tail := tailTest.StartTail("test.txt", Config{Follow: true, Location: nil, MaxLineSize: 4097}) 141 go tailTest.VerifyTailOutput(tail, []string{"test", testString, "hello", "world"}, false) 142 143 // Delete after a reasonable delay, to give tail sufficient time 144 // to read all lines. 145 <-time.After(100 * time.Millisecond) 146 tailTest.RemoveFile("test.txt") 147 tailTest.Cleanup(tail, true) 148 } 149 150 func TestLocationFull(t *testing.T) { 151 tailTest := NewTailTest("location-full", t) 152 tailTest.CreateFile("test.txt", "hello\nworld\n") 153 tail := tailTest.StartTail("test.txt", Config{Follow: true, Location: nil}) 154 go tailTest.VerifyTailOutput(tail, []string{"hello", "world"}, false) 155 156 // Delete after a reasonable delay, to give tail sufficient time 157 // to read all lines. 158 <-time.After(100 * time.Millisecond) 159 tailTest.RemoveFile("test.txt") 160 tailTest.Cleanup(tail, true) 161 } 162 163 func TestLocationFullDontFollow(t *testing.T) { 164 tailTest := NewTailTest("location-full-dontfollow", t) 165 tailTest.CreateFile("test.txt", "hello\nworld\n") 166 tail := tailTest.StartTail("test.txt", Config{Follow: false, Location: nil}) 167 go tailTest.VerifyTailOutput(tail, []string{"hello", "world"}, false) 168 169 // Add more data only after reasonable delay. 170 <-time.After(100 * time.Millisecond) 171 tailTest.AppendFile("test.txt", "more\ndata\n") 172 <-time.After(100 * time.Millisecond) 173 174 tailTest.Cleanup(tail, true) 175 } 176 177 func TestLocationEnd(t *testing.T) { 178 tailTest := NewTailTest("location-end", t) 179 tailTest.CreateFile("test.txt", "hello\nworld\n") 180 tail := tailTest.StartTail("test.txt", Config{Follow: true, Location: &SeekInfo{0, os.SEEK_END}}) 181 go tailTest.VerifyTailOutput(tail, []string{"more", "data"}, false) 182 183 <-time.After(100 * time.Millisecond) 184 tailTest.AppendFile("test.txt", "more\ndata\n") 185 186 // Delete after a reasonable delay, to give tail sufficient time 187 // to read all lines. 188 <-time.After(100 * time.Millisecond) 189 tailTest.RemoveFile("test.txt") 190 tailTest.Cleanup(tail, true) 191 } 192 193 func TestLocationMiddle(t *testing.T) { 194 // Test reading from middle. 195 tailTest := NewTailTest("location-middle", t) 196 tailTest.CreateFile("test.txt", "hello\nworld\n") 197 tail := tailTest.StartTail("test.txt", Config{Follow: true, Location: &SeekInfo{-6, os.SEEK_END}}) 198 go tailTest.VerifyTailOutput(tail, []string{"world", "more", "data"}, false) 199 200 <-time.After(100 * time.Millisecond) 201 tailTest.AppendFile("test.txt", "more\ndata\n") 202 203 // Delete after a reasonable delay, to give tail sufficient time 204 // to read all lines. 205 <-time.After(100 * time.Millisecond) 206 tailTest.RemoveFile("test.txt") 207 tailTest.Cleanup(tail, true) 208 } 209 210 // The use of polling file watcher could affect file rotation 211 // (detected via renames), so test these explicitly. 212 213 func TestReOpenInotify(t *testing.T) { 214 reOpen(t, false) 215 } 216 217 func TestReOpenPolling(t *testing.T) { 218 reOpen(t, true) 219 } 220 221 // The use of polling file watcher could affect file rotation 222 // (detected via renames), so test these explicitly. 223 224 func TestReSeekInotify(t *testing.T) { 225 reSeek(t, false) 226 } 227 228 func TestReSeekPolling(t *testing.T) { 229 reSeek(t, true) 230 } 231 232 func TestRateLimiting(t *testing.T) { 233 tailTest := NewTailTest("rate-limiting", t) 234 tailTest.CreateFile("test.txt", "hello\nworld\nagain\nextra\n") 235 config := Config{ 236 Follow: true, 237 RateLimiter: ratelimiter.NewLeakyBucket(2, time.Second)} 238 leakybucketFull := "Too much log activity; waiting a second before resuming tailing" 239 tail := tailTest.StartTail("test.txt", config) 240 241 // TODO: also verify that tail resumes after the cooloff period. 242 go tailTest.VerifyTailOutput(tail, []string{ 243 "hello", "world", "again", 244 leakybucketFull, 245 "more", "data", 246 leakybucketFull}, false) 247 248 // Add more data only after reasonable delay. 249 <-time.After(1200 * time.Millisecond) 250 tailTest.AppendFile("test.txt", "more\ndata\n") 251 252 // Delete after a reasonable delay, to give tail sufficient time 253 // to read all lines. 254 <-time.After(100 * time.Millisecond) 255 tailTest.RemoveFile("test.txt") 256 257 tailTest.Cleanup(tail, true) 258 } 259 260 func TestTell(t *testing.T) { 261 tailTest := NewTailTest("tell-position", t) 262 tailTest.CreateFile("test.txt", "hello\nworld\nagain\nmore\n") 263 config := Config{ 264 Follow: false, 265 Location: &SeekInfo{0, os.SEEK_SET}} 266 tail := tailTest.StartTail("test.txt", config) 267 // read noe line 268 <-tail.Lines 269 offset, err := tail.Tell() 270 if err != nil { 271 tailTest.Errorf("Tell return error: %s", err.Error()) 272 } 273 tail.Done() 274 // tail.close() 275 276 config = Config{ 277 Follow: false, 278 Location: &SeekInfo{offset, os.SEEK_SET}} 279 tail = tailTest.StartTail("test.txt", config) 280 for l := range tail.Lines { 281 // it may readed one line in the chan(tail.Lines), 282 // so it may lost one line. 283 if l.Text != "world" && l.Text != "again" { 284 tailTest.Fatalf("mismatch; expected world or again, but got %s", 285 l.Text) 286 } 287 break 288 } 289 tailTest.RemoveFile("test.txt") 290 tail.Done() 291 tail.Cleanup() 292 } 293 294 func TestBlockUntilExists(t *testing.T) { 295 tailTest := NewTailTest("block-until-file-exists", t) 296 config := Config{ 297 Follow: true, 298 } 299 tail := tailTest.StartTail("test.txt", config) 300 go func() { 301 time.Sleep(100 * time.Millisecond) 302 tailTest.CreateFile("test.txt", "hello world\n") 303 }() 304 for l := range tail.Lines { 305 if l.Text != "hello world" { 306 tailTest.Fatalf("mismatch; expected hello world, but got %s", 307 l.Text) 308 } 309 break 310 } 311 tailTest.RemoveFile("test.txt") 312 tail.Stop() 313 tail.Cleanup() 314 } 315 316 func maxLineSize(t *testing.T, follow bool, fileContent string, expected []string) { 317 tailTest := NewTailTest("maxlinesize", t) 318 tailTest.CreateFile("test.txt", fileContent) 319 tail := tailTest.StartTail("test.txt", Config{Follow: follow, Location: nil, MaxLineSize: 3}) 320 go tailTest.VerifyTailOutput(tail, expected, false) 321 322 // Delete after a reasonable delay, to give tail sufficient time 323 // to read all lines. 324 <-time.After(100 * time.Millisecond) 325 tailTest.RemoveFile("test.txt") 326 tailTest.Cleanup(tail, true) 327 } 328 329 func reOpen(t *testing.T, poll bool) { 330 var name string 331 var delay time.Duration 332 if poll { 333 name = "reopen-polling" 334 delay = 300 * time.Millisecond // account for POLL_DURATION 335 } else { 336 name = "reopen-inotify" 337 delay = 100 * time.Millisecond 338 } 339 tailTest := NewTailTest(name, t) 340 tailTest.CreateFile("test.txt", "hello\nworld\n") 341 tail := tailTest.StartTail( 342 "test.txt", 343 Config{Follow: true, ReOpen: true, Poll: poll}) 344 content := []string{"hello", "world", "more", "data", "endofworld"} 345 go tailTest.VerifyTailOutput(tail, content, false) 346 347 if poll { 348 // deletion must trigger reopen 349 <-time.After(delay) 350 tailTest.RemoveFile("test.txt") 351 <-time.After(delay) 352 tailTest.CreateFile("test.txt", "more\ndata\n") 353 } else { 354 // In inotify mode, fsnotify is currently unable to deliver notifications 355 // about deletion of open files, so we are not testing file deletion. 356 // (see https://github.com/fsnotify/fsnotify/issues/194 for details). 357 <-time.After(delay) 358 tailTest.AppendToFile("test.txt", "more\ndata\n") 359 } 360 361 // rename must trigger reopen 362 <-time.After(delay) 363 tailTest.RenameFile("test.txt", "test.txt.rotated") 364 <-time.After(delay) 365 tailTest.CreateFile("test.txt", "endofworld\n") 366 367 // Delete after a reasonable delay, to give tail sufficient time 368 // to read all lines. 369 <-time.After(delay) 370 tailTest.RemoveFile("test.txt") 371 <-time.After(delay) 372 373 // Do not bother with stopping as it could kill the tomb during 374 // the reading of data written above. Timings can vary based on 375 // test environment. 376 tailTest.Cleanup(tail, false) 377 } 378 379 func TestInotify_WaitForCreateThenMove(t *testing.T) { 380 tailTest := NewTailTest("wait-for-create-then-reopen", t) 381 os.Remove(tailTest.path + "/test.txt") // Make sure the file does NOT exist. 382 383 tail := tailTest.StartTail( 384 "test.txt", 385 Config{Follow: true, ReOpen: true, Poll: false}) 386 387 content := []string{"hello", "world", "endofworld"} 388 go tailTest.VerifyTailOutput(tail, content, false) 389 390 time.Sleep(50 * time.Millisecond) 391 tailTest.CreateFile("test.txt", "hello\nworld\n") 392 time.Sleep(50 * time.Millisecond) 393 tailTest.RenameFile("test.txt", "test.txt.rotated") 394 time.Sleep(50 * time.Millisecond) 395 tailTest.CreateFile("test.txt", "endofworld\n") 396 time.Sleep(50 * time.Millisecond) 397 tailTest.RemoveFile("test.txt.rotated") 398 tailTest.RemoveFile("test.txt") 399 400 // Do not bother with stopping as it could kill the tomb during 401 // the reading of data written above. Timings can vary based on 402 // test environment. 403 tailTest.Cleanup(tail, false) 404 } 405 406 func reSeek(t *testing.T, poll bool) { 407 var name string 408 if poll { 409 name = "reseek-polling" 410 } else { 411 name = "reseek-inotify" 412 } 413 tailTest := NewTailTest(name, t) 414 tailTest.CreateFile("test.txt", "a really long string goes here\nhello\nworld\n") 415 tail := tailTest.StartTail( 416 "test.txt", 417 Config{Follow: true, ReOpen: false, Poll: poll}) 418 419 go tailTest.VerifyTailOutput(tail, []string{ 420 "a really long string goes here", "hello", "world", "h311o", "w0r1d", "endofworld"}, false) 421 422 // truncate now 423 <-time.After(100 * time.Millisecond) 424 tailTest.TruncateFile("test.txt", "h311o\nw0r1d\nendofworld\n") 425 426 // Delete after a reasonable delay, to give tail sufficient time 427 // to read all lines. 428 <-time.After(100 * time.Millisecond) 429 tailTest.RemoveFile("test.txt") 430 431 // Do not bother with stopping as it could kill the tomb during 432 // the reading of data written above. Timings can vary based on 433 // test environment. 434 tailTest.Cleanup(tail, false) 435 } 436 437 func parseLine(line string) (time.Time, error) { 438 return time.Parse(time.RFC3339, line) 439 } 440 441 func TestDateParse(t *testing.T) { 442 tailTest := NewTailTest("date-parse", t) 443 tailTest.CreateFile("test.txt", "2009-11-10T23:00:00Z\n2009-11-10T23:00:01Z\n") 444 tail := tailTest.StartTail("test.txt", Config{Follow: true, Location: nil, DateParse: parseLine}) 445 line := <-tail.Lines 446 if line.Text != "2009-11-10T23:00:00Z" { 447 t.Errorf("%s != %s", line.Text, "2009-11-10T23:00:00Z") 448 } 449 if line.Time.Unix() != 1257894000 { 450 t.Errorf("%d != %d", line.Time.Unix(), 1257894000) 451 } 452 line = <-tail.Lines 453 if line.Text != "2009-11-10T23:00:01Z" { 454 t.Errorf("%s != %s", line.Text, "2009-11-10T23:00:00Z") 455 } 456 if line.Time.Unix() != 1257894001 { 457 t.Errorf("%d != %d", line.Time.Unix(), 1257894001) 458 } 459 tail.Stop() 460 tail.Cleanup() 461 tailTest.RemoveFile("test.txt") 462 } 463 464 func TestOffset(t *testing.T) { 465 tailTest := NewTailTest("date-parse", t) 466 tailTest.CreateFile("test.txt", "hello\nworld\n") 467 tail := tailTest.StartTail("test.txt", Config{Follow: true, Location: nil}) 468 line := <-tail.Lines 469 if line.Offset != 0 { 470 t.Errorf("%d != %d", line.Offset, 0) 471 } 472 line = <-tail.Lines 473 if line.Offset != 6 { 474 t.Errorf("%d != %d", line.Offset, 6) 475 } 476 tail.Stop() 477 tail.Cleanup() 478 tailTest.RemoveFile("test.txt") 479 } 480 481 // Test library 482 483 type TailTest struct { 484 Name string 485 path string 486 done chan struct{} 487 *testing.T 488 } 489 490 func NewTailTest(name string, t *testing.T) TailTest { 491 tt := TailTest{name, ".test/" + name, make(chan struct{}), t} 492 err := os.MkdirAll(tt.path, os.ModeTemporary|0700) 493 if err != nil { 494 tt.Fatal(err) 495 } 496 497 return tt 498 } 499 500 func (t TailTest) CreateFile(name string, contents string) { 501 err := ioutil.WriteFile(t.path+"/"+name, []byte(contents), 0600) 502 if err != nil { 503 t.Fatal(err) 504 } 505 } 506 507 func (t TailTest) AppendToFile(name string, contents string) { 508 err := ioutil.WriteFile(t.path+"/"+name, []byte(contents), 0600|os.ModeAppend) 509 if err != nil { 510 t.Fatal(err) 511 } 512 } 513 514 func (t TailTest) RemoveFile(name string) { 515 err := os.Remove(t.path + "/" + name) 516 if err != nil { 517 t.Fatal(err) 518 } 519 } 520 521 func (t TailTest) RenameFile(oldname string, newname string) { 522 oldname = t.path + "/" + oldname 523 newname = t.path + "/" + newname 524 err := os.Rename(oldname, newname) 525 if err != nil { 526 t.Fatal(err) 527 } 528 } 529 530 func (t TailTest) AppendFile(name string, contents string) { 531 f, err := os.OpenFile(t.path+"/"+name, os.O_APPEND|os.O_WRONLY, 0600) 532 if err != nil { 533 t.Fatal(err) 534 } 535 defer f.Close() 536 _, err = f.WriteString(contents) 537 if err != nil { 538 t.Fatal(err) 539 } 540 } 541 542 func (t TailTest) TruncateFile(name string, contents string) { 543 f, err := os.OpenFile(t.path+"/"+name, os.O_TRUNC|os.O_WRONLY, 0600) 544 if err != nil { 545 t.Fatal(err) 546 } 547 defer f.Close() 548 _, err = f.WriteString(contents) 549 if err != nil { 550 t.Fatal(err) 551 } 552 } 553 554 func (t TailTest) StartTail(name string, config Config) *Tail { 555 tail, err := TailFile(t.path+"/"+name, config) 556 if err != nil { 557 t.Fatal(err) 558 } 559 return tail 560 } 561 562 func (t TailTest) VerifyTailOutput(tail *Tail, lines []string, expectEOF bool) { 563 defer close(t.done) 564 t.ReadLines(tail, lines) 565 // It is important to do this if only EOF is expected 566 // otherwise we could block on <-tail.Lines 567 if expectEOF { 568 line, ok := <-tail.Lines 569 if ok { 570 t.Fatalf("more content from tail: %+v", line) 571 } 572 } 573 } 574 575 func (t TailTest) ReadLines(tail *Tail, lines []string) { 576 for idx, line := range lines { 577 tailedLine, ok := <-tail.Lines 578 if !ok { 579 // tail.Lines is closed and empty. 580 err := tail.Err() 581 if err != nil { 582 t.Fatalf("tail ended with error: %v", err) 583 } 584 t.Fatalf("tail ended early; expecting more: %v", lines[idx:]) 585 } 586 if tailedLine == nil { 587 t.Fatalf("tail.Lines returned nil; not possible") 588 } 589 // Note: not checking .Err as the `lines` argument is designed 590 // to match error strings as well. 591 if tailedLine.Text != line { 592 t.Fatalf( 593 "unexpected line/err from tail: "+ 594 "expecting <<%s>>>, but got <<<%s>>>", 595 line, tailedLine.Text) 596 } 597 } 598 } 599 600 func (t TailTest) Cleanup(tail *Tail, stop bool) { 601 <-t.done 602 if stop { 603 tail.Stop() 604 } 605 tail.Cleanup() 606 }