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