mirror of
https://github.com/octoleo/syncthing.git
synced 2024-12-23 03:18:59 +00:00
76af9ba53d
This implements a new debug/trace infrastructure based on a slightly hacked up logger. Instead of the traditional "if debug { ... }" I've rewritten the logger to have no-op Debugln and Debugf, unless debugging has been enabled for a given "facility". The "facility" is just a string, typically a package name. This will be slightly slower than before; but not that much as it's mostly a function call that returns immediately. For the cases where it matters (the Debugln takes a hex.Dump() of something for example, and it's not in a very occasional "if err != nil" branch) there is an l.ShouldDebug(facility) that is fast enough to be used like the old "if debug". The point of all this is that we can now toggle debugging for the various packages on and off at runtime. There's a new method /rest/system/debug that can be POSTed a set of facilities to enable and disable debug for, or GET from to get a list of facilities with descriptions and their current debug status. Similarly a /rest/system/log?since=... can grab the latest log entries, up to 250 of them (hardcoded constant in main.go) plus the initial few. Not implemented in this commit (but planned) is a simple debug GUI available on /debug that shows the current log in an easily pasteable format and has checkboxes to enable the various debug facilities. The debug instructions to a user then becomes "visit this URL, check these boxes, reproduce your problem, copy and paste the log". The actual log viewer on the hypothetical /debug URL can poll regularly for new log entries and this bypass the 250 line limit. The existing STTRACE=foo variable is still obeyed and just sets the start state of the system.
141 lines
3.0 KiB
Go
141 lines
3.0 KiB
Go
// Copyright (C) 2014 Jakob Borg. All rights reserved. Use of this source code
|
|
// is governed by an MIT-style license that can be found in the LICENSE file.
|
|
|
|
package logger
|
|
|
|
import (
|
|
"fmt"
|
|
"strings"
|
|
"testing"
|
|
"time"
|
|
)
|
|
|
|
func TestAPI(t *testing.T) {
|
|
l := New()
|
|
l.SetFlags(0)
|
|
l.SetPrefix("testing")
|
|
|
|
debug := 0
|
|
l.AddHandler(LevelDebug, checkFunc(t, LevelDebug, &debug))
|
|
info := 0
|
|
l.AddHandler(LevelInfo, checkFunc(t, LevelInfo, &info))
|
|
ok := 0
|
|
l.AddHandler(LevelOK, checkFunc(t, LevelOK, &ok))
|
|
warn := 0
|
|
l.AddHandler(LevelWarn, checkFunc(t, LevelWarn, &warn))
|
|
|
|
l.Debugf("test %d", 0)
|
|
l.Debugln("test", 0)
|
|
l.Infof("test %d", 1)
|
|
l.Infoln("test", 1)
|
|
l.Okf("test %d", 2)
|
|
l.Okln("test", 2)
|
|
l.Warnf("test %d", 3)
|
|
l.Warnln("test", 3)
|
|
|
|
if debug != 8 {
|
|
t.Errorf("Debug handler called %d != 8 times", debug)
|
|
}
|
|
if info != 6 {
|
|
t.Errorf("Info handler called %d != 6 times", info)
|
|
}
|
|
if ok != 4 {
|
|
t.Errorf("Ok handler called %d != 4 times", ok)
|
|
}
|
|
if warn != 2 {
|
|
t.Errorf("Warn handler called %d != 2 times", warn)
|
|
}
|
|
}
|
|
|
|
func checkFunc(t *testing.T, expectl LogLevel, counter *int) func(LogLevel, string) {
|
|
return func(l LogLevel, msg string) {
|
|
*counter++
|
|
if l < expectl {
|
|
t.Errorf("Incorrect message level %d < %d", l, expectl)
|
|
}
|
|
}
|
|
}
|
|
|
|
func TestFacilityDebugging(t *testing.T) {
|
|
l := New()
|
|
l.SetFlags(0)
|
|
|
|
msgs := 0
|
|
l.AddHandler(LevelDebug, func(l LogLevel, msg string) {
|
|
msgs++
|
|
if strings.Contains(msg, "f1") {
|
|
t.Fatal("Should not get message for facility f1")
|
|
}
|
|
})
|
|
|
|
f0 := l.NewFacility("f0", "foo#0")
|
|
f1 := l.NewFacility("f1", "foo#1")
|
|
|
|
l.SetDebug("f0", true)
|
|
l.SetDebug("f1", false)
|
|
|
|
f0.Debugln("Debug line from f0")
|
|
f1.Debugln("Debug line from f1")
|
|
|
|
if msgs != 1 {
|
|
t.Fatalf("Incorrent number of messages, %d != 1", msgs)
|
|
}
|
|
}
|
|
|
|
func TestRecorder(t *testing.T) {
|
|
l := New()
|
|
l.SetFlags(0)
|
|
|
|
// Keep the last five warnings or higher, no special initial handling.
|
|
r0 := NewRecorder(l, LevelWarn, 5, 0)
|
|
// Keep the last ten infos or higher, with the first three being permanent.
|
|
r1 := NewRecorder(l, LevelInfo, 10, 3)
|
|
|
|
// Log a bunch of messages.
|
|
for i := 0; i < 15; i++ {
|
|
l.Debugf("Debug#%d", i)
|
|
l.Infof("Info#%d", i)
|
|
l.Warnf("Warn#%d", i)
|
|
}
|
|
|
|
// r0 should contain the last five warnings
|
|
lines := r0.Since(time.Time{})
|
|
if len(lines) != 5 {
|
|
t.Fatalf("Incorrect length %d != 5", len(lines))
|
|
}
|
|
for i := 0; i < 5; i++ {
|
|
expected := fmt.Sprintf("Warn#%d", i+10)
|
|
if lines[i].Message != expected {
|
|
t.Error("Incorrect warning in r0:", lines[i].Message, "!=", expected)
|
|
}
|
|
}
|
|
|
|
// r0 should contain:
|
|
// - The first three messages
|
|
// - A "..." marker
|
|
// - The last six messages
|
|
// (totalling ten)
|
|
lines = r1.Since(time.Time{})
|
|
if len(lines) != 10 {
|
|
t.Fatalf("Incorrect length %d != 10", len(lines))
|
|
}
|
|
expected := []string{
|
|
"Info#0",
|
|
"Warn#0",
|
|
"Info#1",
|
|
"...",
|
|
"Info#12",
|
|
"Warn#12",
|
|
"Info#13",
|
|
"Warn#13",
|
|
"Info#14",
|
|
"Warn#14",
|
|
}
|
|
for i := 0; i < 10; i++ {
|
|
if lines[i].Message != expected[i] {
|
|
t.Error("Incorrect warning in r0:", lines[i].Message, "!=", expected[i])
|
|
}
|
|
}
|
|
|
|
}
|