1// Copyright 2009 The Go Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style
3// license that can be found in the LICENSE file.
4
5package log
6
7// These tests are too simple.
8
9import (
10	"bytes"
11	"fmt"
12	"io"
13	"os"
14	"regexp"
15	"strings"
16	"testing"
17	"time"
18)
19
20const (
21	Rdate         = `[0-9][0-9][0-9][0-9]/[0-9][0-9]/[0-9][0-9]`
22	Rtime         = `[0-9][0-9]:[0-9][0-9]:[0-9][0-9]`
23	Rmicroseconds = `\.[0-9][0-9][0-9][0-9][0-9][0-9]`
24	Rline         = `(61|63):` // must update if the calls to l.Printf / l.Print below move
25	Rlongfile     = `.*/[A-Za-z0-9_\-]+\.go:` + Rline
26	Rshortfile    = `[A-Za-z0-9_\-]+\.go:` + Rline
27)
28
29type tester struct {
30	flag    int
31	prefix  string
32	pattern string // regexp that log output must match; we add ^ and expected_text$ always
33}
34
35var tests = []tester{
36	// individual pieces:
37	{0, "", ""},
38	{0, "XXX", "XXX"},
39	{Ldate, "", Rdate + " "},
40	{Ltime, "", Rtime + " "},
41	{Ltime | Lmsgprefix, "XXX", Rtime + " XXX"},
42	{Ltime | Lmicroseconds, "", Rtime + Rmicroseconds + " "},
43	{Lmicroseconds, "", Rtime + Rmicroseconds + " "}, // microsec implies time
44	{Llongfile, "", Rlongfile + " "},
45	{Lshortfile, "", Rshortfile + " "},
46	{Llongfile | Lshortfile, "", Rshortfile + " "}, // shortfile overrides longfile
47	// everything at once:
48	{Ldate | Ltime | Lmicroseconds | Llongfile, "XXX", "XXX" + Rdate + " " + Rtime + Rmicroseconds + " " + Rlongfile + " "},
49	{Ldate | Ltime | Lmicroseconds | Lshortfile, "XXX", "XXX" + Rdate + " " + Rtime + Rmicroseconds + " " + Rshortfile + " "},
50	{Ldate | Ltime | Lmicroseconds | Llongfile | Lmsgprefix, "XXX", Rdate + " " + Rtime + Rmicroseconds + " " + Rlongfile + " XXX"},
51	{Ldate | Ltime | Lmicroseconds | Lshortfile | Lmsgprefix, "XXX", Rdate + " " + Rtime + Rmicroseconds + " " + Rshortfile + " XXX"},
52}
53
54// Test using Println("hello", 23, "world") or using Printf("hello %d world", 23)
55func testPrint(t *testing.T, flag int, prefix string, pattern string, useFormat bool) {
56	buf := new(bytes.Buffer)
57	SetOutput(buf)
58	SetFlags(flag)
59	SetPrefix(prefix)
60	if useFormat {
61		Printf("hello %d world", 23)
62	} else {
63		Println("hello", 23, "world")
64	}
65	line := buf.String()
66	line = line[0 : len(line)-1]
67	pattern = "^" + pattern + "hello 23 world$"
68	matched, err := regexp.MatchString(pattern, line)
69	if err != nil {
70		t.Fatal("pattern did not compile:", err)
71	}
72	if !matched {
73		t.Errorf("log output should match %q is %q", pattern, line)
74	}
75	SetOutput(os.Stderr)
76}
77
78func TestDefault(t *testing.T) {
79	if got := Default(); got != std {
80		t.Errorf("Default [%p] should be std [%p]", got, std)
81	}
82}
83
84func TestAll(t *testing.T) {
85	for _, testcase := range tests {
86		testPrint(t, testcase.flag, testcase.prefix, testcase.pattern, false)
87		testPrint(t, testcase.flag, testcase.prefix, testcase.pattern, true)
88	}
89}
90
91func TestOutput(t *testing.T) {
92	const testString = "test"
93	var b bytes.Buffer
94	l := New(&b, "", 0)
95	l.Println(testString)
96	if expect := testString + "\n"; b.String() != expect {
97		t.Errorf("log output should match %q is %q", expect, b.String())
98	}
99}
100
101func TestOutputRace(t *testing.T) {
102	var b bytes.Buffer
103	l := New(&b, "", 0)
104	for i := 0; i < 100; i++ {
105		go func() {
106			l.SetFlags(0)
107		}()
108		l.Output(0, "")
109	}
110}
111
112func TestFlagAndPrefixSetting(t *testing.T) {
113	var b bytes.Buffer
114	l := New(&b, "Test:", LstdFlags)
115	f := l.Flags()
116	if f != LstdFlags {
117		t.Errorf("Flags 1: expected %x got %x", LstdFlags, f)
118	}
119	l.SetFlags(f | Lmicroseconds)
120	f = l.Flags()
121	if f != LstdFlags|Lmicroseconds {
122		t.Errorf("Flags 2: expected %x got %x", LstdFlags|Lmicroseconds, f)
123	}
124	p := l.Prefix()
125	if p != "Test:" {
126		t.Errorf(`Prefix: expected "Test:" got %q`, p)
127	}
128	l.SetPrefix("Reality:")
129	p = l.Prefix()
130	if p != "Reality:" {
131		t.Errorf(`Prefix: expected "Reality:" got %q`, p)
132	}
133	// Verify a log message looks right, with our prefix and microseconds present.
134	l.Print("hello")
135	pattern := "^Reality:" + Rdate + " " + Rtime + Rmicroseconds + " hello\n"
136	matched, err := regexp.Match(pattern, b.Bytes())
137	if err != nil {
138		t.Fatalf("pattern %q did not compile: %s", pattern, err)
139	}
140	if !matched {
141		t.Error("message did not match pattern")
142	}
143}
144
145func TestUTCFlag(t *testing.T) {
146	var b bytes.Buffer
147	l := New(&b, "Test:", LstdFlags)
148	l.SetFlags(Ldate | Ltime | LUTC)
149	// Verify a log message looks right in the right time zone. Quantize to the second only.
150	now := time.Now().UTC()
151	l.Print("hello")
152	want := fmt.Sprintf("Test:%d/%.2d/%.2d %.2d:%.2d:%.2d hello\n",
153		now.Year(), now.Month(), now.Day(), now.Hour(), now.Minute(), now.Second())
154	got := b.String()
155	if got == want {
156		return
157	}
158	// It's possible we crossed a second boundary between getting now and logging,
159	// so add a second and try again. This should very nearly always work.
160	now = now.Add(time.Second)
161	want = fmt.Sprintf("Test:%d/%.2d/%.2d %.2d:%.2d:%.2d hello\n",
162		now.Year(), now.Month(), now.Day(), now.Hour(), now.Minute(), now.Second())
163	if got == want {
164		return
165	}
166	t.Errorf("got %q; want %q", got, want)
167}
168
169func TestEmptyPrintCreatesLine(t *testing.T) {
170	var b bytes.Buffer
171	l := New(&b, "Header:", LstdFlags)
172	l.Print()
173	l.Println("non-empty")
174	output := b.String()
175	if n := strings.Count(output, "Header"); n != 2 {
176		t.Errorf("expected 2 headers, got %d", n)
177	}
178	if n := strings.Count(output, "\n"); n != 2 {
179		t.Errorf("expected 2 lines, got %d", n)
180	}
181}
182
183func TestDiscard(t *testing.T) {
184	l := New(io.Discard, "", 0)
185	s := strings.Repeat("a", 102400)
186	c := testing.AllocsPerRun(100, func() { l.Printf("%s", s) })
187	// One allocation for slice passed to Printf,
188	// but none for formatting of long string.
189	if c > 1 {
190		t.Errorf("got %v allocs, want at most 1", c)
191	}
192}
193
194func BenchmarkItoa(b *testing.B) {
195	dst := make([]byte, 0, 64)
196	for i := 0; i < b.N; i++ {
197		dst = dst[0:0]
198		itoa(&dst, 2015, 4)   // year
199		itoa(&dst, 1, 2)      // month
200		itoa(&dst, 30, 2)     // day
201		itoa(&dst, 12, 2)     // hour
202		itoa(&dst, 56, 2)     // minute
203		itoa(&dst, 0, 2)      // second
204		itoa(&dst, 987654, 6) // microsecond
205	}
206}
207
208func BenchmarkPrintln(b *testing.B) {
209	const testString = "test"
210	var buf bytes.Buffer
211	l := New(&buf, "", LstdFlags)
212	for i := 0; i < b.N; i++ {
213		buf.Reset()
214		l.Println(testString)
215	}
216}
217
218func BenchmarkPrintlnNoFlags(b *testing.B) {
219	const testString = "test"
220	var buf bytes.Buffer
221	l := New(&buf, "", 0)
222	for i := 0; i < b.N; i++ {
223		buf.Reset()
224		l.Println(testString)
225	}
226}
227