logger/glog: add directory context to output and vmodule matching

This change allows setting the verbosity for directory prefixes
using the syntax:

    --vmodule=eth/=6

2 files changed, 89 insertions, 51 deletions

diff --git a/logger/glog/glog.go b/logger/glog/glog.go
index 008c0e036..ef0c3068c 100644
--- a/logger/glog/glog.go
+++ b/logger/glog/glog.go
@@ -63,11 +63,17 @@
 //		Enable V-leveled logging at the specified level.
 //	-vmodule=""
 //		The syntax of the argument is a comma-separated list of pattern=N,
-//		where pattern is a literal file name (minus the ".go" suffix) or
-//		"glob" pattern and N is a V level. For instance,
-//			-vmodule=gopher*=3
-//		sets the V level to 3 in all Go files whose names begin "gopher".
+//		where pattern is a literal file name or "glob" pattern matching
+//		and N is a V level. For instance,
 //
+//			-vmodule=gopher.go=3
+//		sets the V level to 3 in all Go files named "gopher.go".
+//
+//			-vmodule=foo=3
+//		sets V to 3 in all files of any packages whose import path ends in "foo".
+//
+//			-vmodule=foo/*=3
+//		sets V to 3 in all files of any packages whose import path contains "foo".
 package glog
 
 import (
@@ -78,7 +84,7 @@ import (
 	"io"
 	stdLog "log"
 	"os"
-	"path/filepath"
+	"regexp"
 	"runtime"
 	"strconv"
 	"strings"
@@ -113,6 +119,20 @@ var severityName = []string{
 	fatalLog:   "FATAL",
 }
 
+// these path prefixes are trimmed for display, but not when
+// matching vmodule filters.
+var trimPrefixes = []string{
+	"/github.com/ethereum/go-ethereum",
+	"/github.com/ethereum/ethash",
+}
+
+func trimToImportPath(file string) string {
+	if root := strings.LastIndex(file, "src/"); root != 0 {
+		file = file[root+3:]
+	}
+	return file
+}
+
 // SetV sets the global verbosity level
 func SetV(v int) {
 	logging.verbosity.set(Level(v))
@@ -261,21 +281,10 @@ type moduleSpec struct {
 // modulePat contains a filter for the -vmodule flag.
 // It holds a verbosity level and a file pattern to match.
 type modulePat struct {
-	pattern string
-	literal bool // The pattern is a literal string
+	pattern *regexp.Regexp
 	level   Level
 }
 
-// match reports whether the file matches the pattern. It uses a string
-// comparison if the pattern contains no metacharacters.
-func (m *modulePat) match(file string) bool {
-	if m.literal {
-		return file == m.pattern
-	}
-	match, _ := filepath.Match(m.pattern, file)
-	return match
-}
-
 func (m *moduleSpec) String() string {
 	// Lock because the type is not atomic. TODO: clean this up.
 	logging.mu.Lock()
@@ -322,7 +331,8 @@ func (m *moduleSpec) Set(value string) error {
 			continue // Ignore. It's harmless but no point in paying the overhead.
 		}
 		// TODO: check syntax of filter?
-		filter = append(filter, modulePat{pattern, isLiteral(pattern), Level(v)})
+		re, _ := compileModulePattern(pattern)
+		filter = append(filter, modulePat{re, Level(v)})
 	}
 	logging.mu.Lock()
 	defer logging.mu.Unlock()
@@ -330,10 +340,21 @@ func (m *moduleSpec) Set(value string) error {
 	return nil
 }
 
-// isLiteral reports whether the pattern is a literal string, that is, has no metacharacters
-// that require filepath.Match to be called to match the pattern.
-func isLiteral(pattern string) bool {
-	return !strings.ContainsAny(pattern, `\*?[]`)
+// compiles a vmodule pattern to a regular expression.
+func compileModulePattern(pat string) (*regexp.Regexp, error) {
+	re := ".*"
+	for _, comp := range strings.Split(pat, "/") {
+		if comp == "*" {
+			re += "(/.*)?"
+		} else if comp != "" {
+			// TODO: maybe return error if comp contains *
+			re += "/" + regexp.QuoteMeta(comp)
+		}
+	}
+	if !strings.HasSuffix(pat, ".go") {
+		re += "/[^/]+\\.go"
+	}
+	return regexp.Compile(re + "$")
 }
 
 // traceLocation represents the setting of the -log_backtrace_at flag.
@@ -556,10 +577,14 @@ func (l *loggingT) header(s severity, depth int) (*buffer, string, int) {
 		file = "???"
 		line = 1
 	} else {
-		slash := strings.LastIndex(file, "/")
-		if slash >= 0 {
-			file = file[slash+1:]
+		file = trimToImportPath(file)
+		for _, p := range trimPrefixes {
+			if strings.HasPrefix(file, p) {
+				file = file[len(p):]
+				break
+			}
 		}
+		file = file[1:] // drop '/'
 	}
 	return l.formatHeader(s, file, line), file, line
 }
@@ -592,9 +617,7 @@ func (l *loggingT) formatHeader(s severity, file string, line int) *buffer {
 	buf.tmp[14] = '.'
 	buf.nDigits(6, 15, now.Nanosecond()/1000, '0')
 	buf.tmp[21] = ' '
-	buf.nDigits(7, 22, pid, ' ') // TODO: should be TID
-	buf.tmp[29] = ' '
-	buf.Write(buf.tmp[:30])
+	buf.Write(buf.tmp[:22])
 	buf.WriteString(file)
 	buf.tmp[0] = ':'
 	n := buf.someDigits(1, line)
@@ -976,15 +999,9 @@ func (lb logBridge) Write(b []byte) (n int, err error) {
 func (l *loggingT) setV(pc uintptr) Level {
 	fn := runtime.FuncForPC(pc)
 	file, _ := fn.FileLine(pc)
-	// The file is something like /a/b/c/d.go. We want just the d.
-	if strings.HasSuffix(file, ".go") {
-		file = file[:len(file)-3]
-	}
-	if slash := strings.LastIndex(file, "/"); slash >= 0 {
-		file = file[slash+1:]
-	}
+	file = trimToImportPath(file)
 	for _, filter := range l.vmodule.filter {
-		if filter.match(file) {
+		if filter.pattern.MatchString(file) {
 			l.vmap[pc] = filter.level
 			return filter.level
 		}
diff --git a/logger/glog/glog_test.go b/logger/glog/glog_test.go
index 0fb376e1f..30861a48d 100644
--- a/logger/glog/glog_test.go
+++ b/logger/glog/glog_test.go
@@ -180,7 +180,7 @@ func TestHeader(t *testing.T) {
 	pid = 1234
 	Info("test")
 	var line int
-	format := "I0102 15:04:05.067890    1234 glog_test.go:%d] test\n"
+	format := "I0102 15:04:05.067890 logger/glog/glog_test.go:%d] test\n"
 	n, err := fmt.Sscanf(contents(infoLog), format, &line)
 	if n != 1 || err != nil {
 		t.Errorf("log format error: %d elements, error %s:\n%s", n, err, contents(infoLog))
@@ -253,7 +253,7 @@ func TestV(t *testing.T) {
 func TestVmoduleOn(t *testing.T) {
 	setFlags()
 	defer logging.swap(logging.newBuffers())
-	logging.vmodule.Set("glog_test=2")
+	logging.vmodule.Set("glog_test.go=2")
 	defer logging.vmodule.Set("")
 	if !V(1) {
 		t.Error("V not enabled for 1")
@@ -290,22 +290,43 @@ func TestVmoduleOff(t *testing.T) {
 	}
 }
 
+var patternTests = []struct{ input, want string }{
+	{"foo/bar/x.go", ".*/foo/bar/x\\.go$"},
+	{"foo/*/x.go", ".*/foo(/.*)?/x\\.go$"},
+	{"foo/*", ".*/foo(/.*)?/[^/]+\\.go$"},
+}
+
+func TestCompileModulePattern(t *testing.T) {
+	for _, test := range patternTests {
+		re, err := compileModulePattern(test.input)
+		if err != nil {
+			t.Fatalf("%s: %v", err)
+		}
+		if re.String() != test.want {
+			t.Errorf("mismatch for %q: got %q, want %q", test.input, re.String(), test.want)
+		}
+	}
+}
+
 // vGlobs are patterns that match/don't match this file at V=2.
 var vGlobs = map[string]bool{
 	// Easy to test the numeric match here.
-	"glog_test=1": false, // If -vmodule sets V to 1, V(2) will fail.
-	"glog_test=2": true,
-	"glog_test=3": true, // If -vmodule sets V to 1, V(3) will succeed.
-	// These all use 2 and check the patterns. All are true.
-	"*=2":           true,
-	"?l*=2":         true,
-	"????_*=2":      true,
-	"??[mno]?_*t=2": true,
-	// These all use 2 and check the patterns. All are false.
-	"*x=2":         false,
-	"m*=2":         false,
-	"??_*=2":       false,
-	"?[abc]?_*t=2": false,
+	"glog_test.go=1": false, // If -vmodule sets V to 1, V(2) will fail.
+	"glog_test.go=2": true,
+	"glog_test.go=3": true, // If -vmodule sets V to 1, V(3) will succeed.
+
+	// Import path prefix matching
+	"logger/glog=1": false,
+	"logger/glog=2": true,
+	"logger/glog=3": true,
+
+	// Import path glob matching
+	"logger/*=1": false,
+	"logger/*=2": true,
+	"logger/*=3": true,
+
+	// These all use 2 and check the patterns.
+	"*=2": true,
 }
 
 // Test that vmodule globbing works as advertised.