restic/internal/debug/debug.go

204 lines
3.7 KiB
Go
Raw Normal View History

2015-01-14 21:08:48 +00:00
// +build debug
package debug
import (
"fmt"
"log"
"os"
"path"
"path/filepath"
2015-01-14 21:08:48 +00:00
"runtime"
"strings"
2017-07-23 12:21:03 +00:00
"github.com/restic/restic/internal/fs"
"github.com/restic/restic/internal/errors"
2015-01-14 21:08:48 +00:00
)
var opts struct {
2015-04-30 05:05:58 +00:00
logger *log.Logger
2016-09-27 20:23:34 +00:00
funcs map[string]bool
files map[string]bool
2015-01-14 21:08:48 +00:00
}
// make sure that all the initialization happens before the init() functions
// are called, cf https://golang.org/ref/spec#Package_initialization
var _ = initDebug()
func initDebug() bool {
2015-04-30 05:05:58 +00:00
initDebugLogger()
initDebugTags()
2015-01-14 21:08:48 +00:00
fmt.Fprintf(os.Stderr, "debug enabled\n")
return true
2015-04-30 05:05:58 +00:00
}
2015-01-14 21:08:48 +00:00
2015-04-30 05:05:58 +00:00
func initDebugLogger() {
2015-01-14 21:08:48 +00:00
debugfile := os.Getenv("DEBUG_LOG")
2015-04-30 05:05:58 +00:00
if debugfile == "" {
return
}
2015-04-30 05:05:58 +00:00
fmt.Fprintf(os.Stderr, "debug log file %v\n", debugfile)
2015-01-14 21:08:48 +00:00
f, err := fs.OpenFile(debugfile, os.O_WRONLY|os.O_APPEND, 0600)
2015-04-30 05:05:58 +00:00
if err == nil {
_, err = f.Seek(2, 0)
2015-01-14 21:08:48 +00:00
if err != nil {
2015-04-30 05:05:58 +00:00
fmt.Fprintf(os.Stderr, "unable to seek to the end of %v: %v\n", debugfile, err)
os.Exit(3)
2015-01-14 21:08:48 +00:00
}
2015-04-30 05:05:58 +00:00
}
if err != nil && os.IsNotExist(errors.Cause(err)) {
f, err = fs.OpenFile(debugfile, os.O_WRONLY|os.O_CREATE|os.O_TRUNC, 0600)
2015-04-30 05:05:58 +00:00
}
2015-01-14 21:08:48 +00:00
2015-04-30 05:05:58 +00:00
if err != nil {
fmt.Fprintf(os.Stderr, "unable to open debug log file: %v\n", err)
os.Exit(2)
2015-01-14 21:08:48 +00:00
}
2015-04-30 05:05:58 +00:00
opts.logger = log.New(f, "", log.LstdFlags)
}
2016-09-27 20:23:34 +00:00
func parseFilter(envname string, pad func(string) string) map[string]bool {
filter := make(map[string]bool)
2015-01-14 21:08:48 +00:00
2016-09-27 20:23:34 +00:00
env := os.Getenv(envname)
if env == "" {
return filter
2015-04-30 05:05:58 +00:00
}
2016-09-27 20:23:34 +00:00
for _, fn := range strings.Split(env, ",") {
t := pad(strings.TrimSpace(fn))
2015-04-30 05:05:58 +00:00
val := true
if t[0] == '-' {
val = false
t = t[1:]
} else if t[0] == '+' {
val = true
t = t[1:]
}
// test pattern
_, err := path.Match(t, "")
if err != nil {
fmt.Fprintf(os.Stderr, "error: invalid pattern %q: %v\n", t, err)
os.Exit(5)
2015-01-14 21:08:48 +00:00
}
2016-09-27 20:23:34 +00:00
filter[t] = val
}
return filter
}
func padFunc(s string) string {
if s == "all" {
return s
}
return s
}
func padFile(s string) string {
if s == "all" {
return s
}
if !strings.Contains(s, "/") {
s = "*/" + s
}
if !strings.Contains(s, ":") {
s = s + ":*"
}
return s
}
func initDebugTags() {
opts.funcs = parseFilter("DEBUG_FUNCS", padFunc)
opts.files = parseFilter("DEBUG_FILES", padFile)
2015-04-30 05:05:58 +00:00
}
2015-01-14 21:08:48 +00:00
// taken from https://github.com/VividCortex/trace
func goroutineNum() int {
b := make([]byte, 20)
runtime.Stack(b, false)
var num int
fmt.Sscanf(string(b), "goroutine %d ", &num)
return num
}
// taken from https://github.com/VividCortex/trace
2016-09-27 20:23:34 +00:00
func getPosition() (fn, dir, file string, line int) {
pc, file, line, ok := runtime.Caller(2)
if !ok {
2016-09-27 20:23:34 +00:00
return "", "", "", 0
}
dirname, filename := filepath.Base(filepath.Dir(file)), filepath.Base(file)
Func := runtime.FuncForPC(pc)
return path.Base(Func.Name()), dirname, filename, line
2016-09-27 20:23:34 +00:00
}
func checkFilter(filter map[string]bool, key string) bool {
// check if key is enabled directly
if v, ok := filter[key]; ok {
return v
}
// check for globbing
for k, v := range filter {
if m, _ := path.Match(k, key); m {
return v
}
}
// check if tag "all" is enabled
if v, ok := filter["all"]; ok && v {
return true
}
2016-09-27 20:23:34 +00:00
return false
}
2016-09-27 20:23:34 +00:00
// Log prints a message to the debug log (if debug is enabled).
2016-09-27 20:35:08 +00:00
func Log(f string, args ...interface{}) {
2016-09-27 20:23:34 +00:00
fn, dir, file, line := getPosition()
2015-10-26 19:10:03 +00:00
goroutine := goroutineNum()
if len(f) == 0 || f[len(f)-1] != '\n' {
2015-02-07 16:04:20 +00:00
f += "\n"
}
2016-09-27 20:23:34 +00:00
pos := fmt.Sprintf("%s/%s:%d", dir, file, line)
formatString := fmt.Sprintf("%s\t%s\t%d\t%s", pos, fn, goroutine, f)
2015-01-14 21:08:48 +00:00
dbgprint := func() {
fmt.Fprintf(os.Stderr, formatString, args...)
2015-01-14 21:08:48 +00:00
}
2015-04-30 05:05:58 +00:00
if opts.logger != nil {
opts.logger.Printf(formatString, args...)
2015-01-14 21:08:48 +00:00
}
2016-09-27 20:23:34 +00:00
if checkFilter(opts.files, fmt.Sprintf("%s/%s:%d", dir, file, line)) {
dbgprint()
2015-01-14 21:08:48 +00:00
return
}
2016-09-27 20:23:34 +00:00
if checkFilter(opts.funcs, fn) {
2015-01-14 21:08:48 +00:00
dbgprint()
}
}