restic/debug/debug.go

232 lines
4.3 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"
"strconv"
2015-01-14 21:08:48 +00:00
"strings"
"sync"
"syscall"
)
var opts struct {
2015-04-30 05:05:58 +00:00
logger *log.Logger
2015-01-14 21:08:48 +00:00
tags map[string]bool
breaks map[string]bool
m sync.Mutex
}
// 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()
initDebugBreaks()
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
2015-04-30 05:05:58 +00:00
f, err := os.OpenFile(debugfile, os.O_WRONLY|os.O_APPEND, 0600)
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(err) {
f, err = os.OpenFile(debugfile, os.O_WRONLY|os.O_CREATE, 0600)
}
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)
}
func initDebugTags() {
opts.tags = make(map[string]bool)
2015-01-14 21:08:48 +00:00
// defaults
opts.tags["break"] = true
// initialize tags
env := os.Getenv("DEBUG_TAGS")
2015-04-30 05:05:58 +00:00
if len(env) == 0 {
return
}
tags := []string{}
for _, tag := range strings.Split(env, ",") {
t := strings.TrimSpace(tag)
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
}
2015-04-30 05:05:58 +00:00
opts.tags[t] = val
tags = append(tags, tag)
2015-01-14 21:08:48 +00:00
}
2015-04-30 05:05:58 +00:00
fmt.Fprintf(os.Stderr, "debug log enabled for: %v\n", tags)
}
2015-01-14 21:08:48 +00:00
2015-04-30 05:05:58 +00:00
func initDebugBreaks() {
opts.breaks = make(map[string]bool)
env := os.Getenv("DEBUG_BREAK")
if len(env) == 0 {
return
}
breaks := []string{}
2015-01-14 21:08:48 +00:00
2015-04-30 05:05:58 +00:00
for _, tag := range strings.Split(env, ",") {
t := strings.TrimSpace(tag)
opts.breaks[t] = true
breaks = append(breaks, t)
2015-01-14 21:08:48 +00:00
}
2015-04-30 05:05:58 +00:00
fmt.Fprintf(os.Stderr, "debug breaks enabled for: %v\n", breaks)
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
func getPosition() string {
_, file, line, ok := runtime.Caller(2)
if !ok {
return ""
}
goroutine := goroutineNum()
return fmt.Sprintf("%3d %s:%3d", goroutine, filepath.Base(file), line)
}
var maxTagLen = 10
2015-01-14 21:08:48 +00:00
func Log(tag string, f string, args ...interface{}) {
opts.m.Lock()
defer opts.m.Unlock()
2015-02-07 16:04:20 +00:00
if f[len(f)-1] != '\n' {
f += "\n"
}
if len(tag) > maxTagLen {
maxTagLen = len(tag)
}
formatStringTag := "[%" + strconv.FormatInt(int64(maxTagLen), 10) + "s]"
formatString := fmt.Sprintf(formatStringTag+" %s %s", tag, getPosition(), 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
}
// check if tag is enabled directly
if v, ok := opts.tags[tag]; ok {
if v {
dbgprint()
}
return
}
// check for globbing
for k, v := range opts.tags {
if m, _ := path.Match(k, tag); m {
if v {
dbgprint()
}
return
}
}
// check if tag "all" is enabled
if v, ok := opts.tags["all"]; ok && v {
dbgprint()
}
}
2015-04-09 20:34:25 +00:00
// Break stops the program if the debug tag is active and the string in tag is
2015-03-15 13:00:28 +00:00
// contained in the DEBUG_BREAK environment variable.
2015-01-14 21:08:48 +00:00
func Break(tag string) {
// check if breaking is enabled
if v, ok := opts.breaks[tag]; !ok || !v {
return
}
_, file, line, _ := runtime.Caller(1)
Log("break", "stopping process %d at %s (%v:%v)\n", os.Getpid(), tag, file, line)
p, err := os.FindProcess(os.Getpid())
if err != nil {
panic(err)
}
err = p.Signal(syscall.SIGSTOP)
if err != nil {
panic(err)
}
}
2015-03-15 13:00:28 +00:00
2015-04-09 20:34:25 +00:00
// BreakIf stops the program if the debug tag is active and the string in tag
2015-03-15 13:00:28 +00:00
// is contained in the DEBUG_BREAK environment variable and the return value of
// fn is true.
func BreakIf(tag string, fn func() bool) {
// check if breaking is enabled
if v, ok := opts.breaks[tag]; !ok || !v {
return
}
2015-03-15 13:00:28 +00:00
if fn() {
Break(tag)
}
}