From 959da0a76a59bd4346ee890d992bf1e7f0f919ee Mon Sep 17 00:00:00 2001
From: Alexander Neumann <alexander@bumpern.de>
Date: Sat, 2 May 2015 00:48:26 +0200
Subject: [PATCH 1/2] debug: Add location to log, improve formatting

Before:

    2015/05/02 00:38:46 [restic] main []string{"./restic", "backup", "."}

After:

    2015/05/02 00:47:42 [  restic]   1 main.go:176    main []string{"./restic", "backup", "-f", "."}
---
 debug/debug.go | 29 +++++++++++++++++++++++++++--
 1 file changed, 27 insertions(+), 2 deletions(-)

diff --git a/debug/debug.go b/debug/debug.go
index 55a47198c..12aa2cb1d 100644
--- a/debug/debug.go
+++ b/debug/debug.go
@@ -7,6 +7,7 @@ import (
 	"log"
 	"os"
 	"path"
+	"path/filepath"
 	"runtime"
 	"strings"
 	"sync"
@@ -122,6 +123,28 @@ func initDebugBreaks() {
 	fmt.Fprintf(os.Stderr, "debug breaks enabled for: %v\n", breaks)
 }
 
+// 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)
+}
+
 func Log(tag string, f string, args ...interface{}) {
 	opts.m.Lock()
 	defer opts.m.Unlock()
@@ -130,12 +153,14 @@ func Log(tag string, f string, args ...interface{}) {
 		f += "\n"
 	}
 
+	formatString := fmt.Sprintf("[% 25s] %-20s %s", tag, getPosition(), f)
+
 	dbgprint := func() {
-		fmt.Fprintf(os.Stderr, "DEBUG["+tag+"]: "+f, args...)
+		fmt.Fprintf(os.Stderr, formatString, args...)
 	}
 
 	if opts.logger != nil {
-		opts.logger.Printf("["+tag+"] "+f, args...)
+		opts.logger.Printf(formatString, args...)
 	}
 
 	// check if tag is enabled directly

From 813031a98992e4d56b6b8ad577e3fd1fcdc7d7b9 Mon Sep 17 00:00:00 2001
From: Alexander Neumann <alexander@bumpern.de>
Date: Sat, 2 May 2015 01:13:07 +0200
Subject: [PATCH 2/2] debug: Dynamically pad tag in debug log

---
 debug/debug.go | 10 +++++++++-
 1 file changed, 9 insertions(+), 1 deletion(-)

diff --git a/debug/debug.go b/debug/debug.go
index 12aa2cb1d..a77cb3836 100644
--- a/debug/debug.go
+++ b/debug/debug.go
@@ -9,6 +9,7 @@ import (
 	"path"
 	"path/filepath"
 	"runtime"
+	"strconv"
 	"strings"
 	"sync"
 	"syscall"
@@ -145,6 +146,8 @@ func getPosition() string {
 	return fmt.Sprintf("%3d %s:%3d", goroutine, filepath.Base(file), line)
 }
 
+var maxTagLen = 10
+
 func Log(tag string, f string, args ...interface{}) {
 	opts.m.Lock()
 	defer opts.m.Unlock()
@@ -153,7 +156,12 @@ func Log(tag string, f string, args ...interface{}) {
 		f += "\n"
 	}
 
-	formatString := fmt.Sprintf("[% 25s] %-20s %s", tag, getPosition(), f)
+	if len(tag) > maxTagLen {
+		maxTagLen = len(tag)
+	}
+
+	formatStringTag := "[%" + strconv.FormatInt(int64(maxTagLen), 10) + "s]"
+	formatString := fmt.Sprintf(formatStringTag+" %s %s", tag, getPosition(), f)
 
 	dbgprint := func() {
 		fmt.Fprintf(os.Stderr, formatString, args...)