"time";
)
-// Lshortname can be or'd in to cause only the last element of the file name to be printed.
const (
+ // Flags
Lok = iota;
Lexit; // terminate execution when written
Lcrash; // crash (panic) when written
- Lshortname = 1 << 5;
+ // Bits or'ed together to control what's printed. There is no control over the
+ // order they appear (the order listed here) or the format they present (as
+ // described in the comments). A colon appears after these items:
+ // 2009/0123 01:23:23.123123 /a/b/c/d.go:23: message
+ Ldate = 1 << iota; // the date: 2009/0123
+ Ltime; // the time: 01:23:23
+ Lmicroseconds; // microsecond resolution: 01:23:23.123123. assumes Ltime.
+ Llongfile; // full file name and line number: /a/b/c/d.go:23
+ Lshortfile; // final file name element and line number: d.go:23. overrides Llongfile
+ lAllBits = Ldate | Ltime | Lmicroseconds | Llongfile | Lshortfile;
)
type Logger struct {
out0 io.Write;
out1 io.Write;
+ prefix string;
flag int;
}
-func NewLogger(out0, out1 io.Write, flag int) *Logger {
- return &Logger{out0, out1, flag}
+func NewLogger(out0, out1 io.Write, prefix string, flag int) *Logger {
+ return &Logger{out0, out1, prefix, flag}
}
var (
- stdout = NewLogger(os.Stdout, nil, Lok);
- stderr = NewLogger(os.Stderr, nil, Lok);
- exit = NewLogger(os.Stderr, nil, Lexit);
- crash = NewLogger(os.Stderr, nil, Lcrash);
+ stdout = NewLogger(os.Stdout, nil, "", Lok|Ldate|Ltime);
+ stderr = NewLogger(os.Stderr, nil, "", Lok|Ldate|Ltime);
+ exit = NewLogger(os.Stderr, nil, "", Lexit|Ldate|Ltime);
+ crash = NewLogger(os.Stderr, nil, "", Lcrash|Ldate|Ltime);
)
-func timestamp(ns int64) string {
- t := time.SecondsToLocalTime(ns/1e9);
- // why are time fields private?
- s := t.RFC1123();
- return s[5:12] + s[17:25]; // TODO(r): placeholder. this gives "24 Jan 15:50:18"
+var shortnames = make(map[string] string) // cache of short names to avoid allocation.
+
+// Cheap integer to fixed-width decimal ASCII. Use a negative width to avoid zero-padding
+func itoa(i int, wid int) string {
+ var u uint = uint(i);
+ if u == 0 && wid <= 1 {
+ return "0"
+ }
+
+ // Assemble decimal in reverse order.
+ var b [32]byte;
+ bp := len(b);
+ for ; u > 0 || wid > 0; u /= 10 {
+ bp--;
+ wid--;
+ b[bp] = byte(u%10) + '0';
+ }
+
+ return string(b[bp:len(b)])
}
-var shortnames = make(map[string] string) // cache of short names to avoid allocation.
+func (l *Logger) formatHeader(ns int64, calldepth int) string {
+ h := l.prefix;
+ if l.flag & (Ldate | Ltime | Lmicroseconds) != 0 {
+ t := time.SecondsToLocalTime(ns/1e9);
+ if l.flag & (Ldate) != 0 {
+ h += itoa(int(t.Year), 4) + "/" + itoa(t.Month, 2) + itoa(t.Day, 2) + " "
+ }
+ if l.flag & (Ltime | Lmicroseconds) != 0 {
+ h += itoa(t.Hour, 2) + ":" + itoa(t.Minute, 2) + ":" + itoa(t.Second, 2);
+ if l.flag & Lmicroseconds != 0 {
+ h += "." + itoa(int(ns % 1e9)/1e3, 6);
+ }
+ h += " ";
+ }
+ }
+ if l.flag & (Lshortfile | Llongfile) != 0 {
+ pc, file, line, ok := sys.Caller(calldepth);
+ if ok {
+ if l.flag & Lshortfile != 0 {
+ short, ok := shortnames[file];
+ if !ok {
+ short = file;
+ for i := len(file) - 1; i > 0; i-- {
+ if file[i] == '/' {
+ short = file[i+1:len(file)];
+ break;
+ }
+ }
+ shortnames[file] = short;
+ }
+ file = short;
+ }
+ } else {
+ file = "???";
+ line = 0;
+ }
+ h += file + ":" + itoa(line, -1) + ": ";
+ }
+ return h;
+}
// The calldepth is provided for generality, although at the moment on all paths it will be 2.
-func (l *Logger) output(calldepth int, s string) {
+func (l *Logger) Output(calldepth int, s string) {
now := time.Nanoseconds(); // get this early.
newline := "\n";
if len(s) > 0 && s[len(s)-1] == '\n' {
newline = ""
}
- pc, file, line, ok := sys.Caller(calldepth);
- if ok {
- if l.flag & Lshortname == Lshortname {
- short, ok := shortnames[file];
- if !ok {
- short = file;
- for i := len(file) - 1; i > 0; i-- {
- if file[i] == '/' {
- short = file[i+1:len(file)];
- shortnames[file] = short;
- break;
- }
- }
- }
- file = short;
- }
- } else {
- file = "???";
- line = 0;
- }
- s = fmt.Sprintf("%s %s:%d: %s%s", timestamp(now), file, line, s, newline);
+ s = l.formatHeader(now, calldepth+1) + s + newline;
io.WriteString(l.out0, s);
if l.out1 != nil {
io.WriteString(l.out1, s);
}
- switch l.flag & ^Lshortname {
+ switch l.flag & ^lAllBits {
case Lcrash:
panic("log: fatal error");
case Lexit:
// Basic methods on Logger, analogous to Printf and Print
func (l *Logger) Logf(format string, v ...) {
- l.output(2, fmt.Sprintf(format, v))
+ l.Output(2, fmt.Sprintf(format, v))
}
func (l *Logger) Log(v ...) {
- l.output(2, fmt.Sprintln(v))
+ l.Output(2, fmt.Sprintln(v))
}
// Helper functions for lightweight simple logging to predefined Loggers.
func Stdout(v ...) {
- stdout.output(2, fmt.Sprint(v))
+ stdout.Output(2, fmt.Sprint(v))
}
func Stderr(v ...) {
- stdout.output(2, fmt.Sprintln(v))
+ stdout.Output(2, fmt.Sprintln(v))
}
func Stdoutf(format string, v ...) {
- stdout.output(2, fmt.Sprintf(format, v))
+ stdout.Output(2, fmt.Sprintf(format, v))
}
func Stderrf(format string, v ...) {
- stderr.output(2, fmt.Sprintf(format, v))
+ stderr.Output(2, fmt.Sprintf(format, v))
}
func Exit(v ...) {
- exit.output(2, fmt.Sprintln(v))
+ exit.Output(2, fmt.Sprintln(v))
}
func Exitf(format string, v ...) {
- exit.output(2, fmt.Sprintf(format, v))
+ exit.Output(2, fmt.Sprintf(format, v))
}
func Crash(v ...) {
- crash.output(2, fmt.Sprintln(v))
+ crash.Output(2, fmt.Sprintln(v))
}
func Crashf(format string, v ...) {
- crash.output(2, fmt.Sprintf(format, v))
+ crash.Output(2, fmt.Sprintf(format, v))
}
"bufio";
"log";
"os";
+ "regexp";
"testing";
)
-func test(t *testing.T, flag int, expect string) {
- fd0, fd1, err1 := os.Pipe();
- if err1 != nil {
- t.Error("pipe", err1);
- }
- buf, err2 := bufio.NewBufRead(fd0);
- if err2 != nil {
- t.Error("bufio.NewBufRead", err2);
- }
- l := NewLogger(fd1, nil, flag);
- l.Log("hello", 23, "world"); /// the line number of this line needs to be placed in the expect strings
- line, err3 := buf.ReadLineString('\n', false);
- if line[len(line)-len(expect):len(line)] != expect {
- t.Error("log output should be ...", expect, "; is " , line);
- }
- t.Log(line);
- fd0.Close();
- fd1.Close();
-}
+const (
+ Rdate = `[0-9][0-9][0-9][0-9]/[0-9][0-9][0-9][0-9]`;
+ Rtime = `[0-9][0-9]:[0-9][0-9]:[0-9][0-9]`;
+ Rmicroseconds = `\.[0-9][0-9][0-9][0-9][0-9][0-9]`;
+ Rline = `[0-9]+:`;
+ Rlongfile = `/[A-Za-z0-9_/]+\.go:` + Rline;
+ Rshortfile = `[A-Za-z0-9_]+\.go:` + Rline;
+)
-func TestRegularLog(t *testing.T) {
- test(t, Lok, "/go/src/lib/log_test.go:25: hello 23 world");
+type tester struct {
+ flag int;
+ prefix string;
+ pattern string; // regexp that log output must match; we add ^ and expected_text$ always
}
-func TestShortNameLog(t *testing.T) {
- test(t, Lok|Lshortname, " log_test.go:25: hello 23 world")
+var tests = []tester {
+ // individual pieces:
+ tester{ 0, "", "" },
+ tester{ 0, "XXX", "XXX" },
+ tester{ Lok|Ldate, "", Rdate+" " },
+ tester{ Lok|Ltime, "", Rtime+" " },
+ tester{ Lok|Ltime|Lmicroseconds, "", Rtime+Rmicroseconds+" " },
+ tester{ Lok|Lmicroseconds, "", Rtime+Rmicroseconds+" " }, // microsec implies time
+ tester{ Lok|Llongfile, "", Rlongfile+" " },
+ tester{ Lok|Lshortfile, "", Rshortfile+" " },
+ tester{ Lok|Llongfile|Lshortfile, "", Rshortfile+" " }, // shortfile overrides longfile
+ // everything at once:
+ tester{ Lok|Ldate|Ltime|Lmicroseconds|Llongfile, "XXX", "XXX"+Rdate+" "+Rtime+Rmicroseconds+" "+Rlongfile+" " },
+ tester{ Lok|Ldate|Ltime|Lmicroseconds|Lshortfile, "XXX", "XXX"+Rdate+" "+Rtime+Rmicroseconds+" "+Rshortfile+" " },
}
-func testFormatted(t *testing.T, flag int, expect string) {
+// Test using Log("hello", 23, "world") or using Logf("hello %d world", 23)
+func testLog(t *testing.T, flag int, prefix string, pattern string, useLogf bool) {
fd0, fd1, err1 := os.Pipe();
if err1 != nil {
- t.Error("pipe", err1);
+ t.Fatal("pipe", err1);
}
buf, err2 := bufio.NewBufRead(fd0);
if err2 != nil {
- t.Error("bufio.NewBufRead", err2);
+ t.Fatal("bufio.NewBufRead", err2);
+ }
+ l := NewLogger(fd1, nil, prefix, flag);
+ if useLogf {
+ l.Logf("hello %d world", 23);
+ } else {
+ l.Log("hello", 23, "world");
}
- l := NewLogger(fd1, nil, flag);
- l.Logf("hello %d world", 23); /// the line number of this line needs to be placed in the expect strings
line, err3 := buf.ReadLineString('\n', false);
- if line[len(line)-len(expect):len(line)] != expect {
- t.Error("log output should be ...", expect, "; is " , line);
+ if err3 != nil {
+ t.Fatal("log error", err3);
+ }
+ pattern = "^"+pattern+"hello 23 world$";
+ matched, err4 := regexp.Match(pattern, line);
+ if err4 != nil{
+ t.Fatal("pattern did not compile:", err4);
+ }
+ if !matched {
+ t.Errorf("log output should match %q is %q", pattern, line);
}
- t.Log(line);
fd0.Close();
fd1.Close();
}
-func TestRegularLogFormatted(t *testing.T) {
- testFormatted(t, Lok, "/go/src/lib/log_test.go:53: hello 23 world");
-}
-
-func TestShortNameLogFormatted(t *testing.T) {
- testFormatted(t, Lok|Lshortname, " log_test.go:53: hello 23 world")
+func TestAllLog(t *testing.T) {
+ for i, testcase := range(tests) {
+ testLog(t, testcase.flag, testcase.prefix, testcase.pattern, false);
+ testLog(t, testcase.flag, testcase.prefix, testcase.pattern, true);
+ }
}