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