diff --git a/.vendor/src/github.com/rubyist/tracerx/README.md b/.vendor/src/github.com/rubyist/tracerx/README.md index d6447324..d294f77d 100644 --- a/.vendor/src/github.com/rubyist/tracerx/README.md +++ b/.vendor/src/github.com/rubyist/tracerx/README.md @@ -18,6 +18,10 @@ tracerx.DefaultKey = "FOO" tracerx.Printf("send message") tracerx.PrintfKey("BAR", "do a thing") + +t := time.Now() +// Do some stuff +tracerx.PerformanceSince("BAR", "command x", t) ``` This example will send tracing output based on the environment variables `FOO_TRACE` and `BAR_TRACE`. @@ -31,6 +35,9 @@ absolute path: output will be written to the file 3 - 10: output will be written to that file descriptor ``` +If an associated `BAR_TRACE_PERFORMANCE` is set to 1 or "true", the `PerformanceSince` line will +output timing information. + Keys can also be disabled. See the GoDoc for full API documentation. ## Bugs, Issues, Feedback diff --git a/.vendor/src/github.com/rubyist/tracerx/tracerx.go b/.vendor/src/github.com/rubyist/tracerx/tracerx.go index 6b2f845a..2e6ac97e 100644 --- a/.vendor/src/github.com/rubyist/tracerx/tracerx.go +++ b/.vendor/src/github.com/rubyist/tracerx/tracerx.go @@ -14,6 +14,9 @@ // By default, messages will be prefixed with "trace: ". This prefix can be // modified by setting Prefix. // +// Each key can have an associated performance key, e.g. TRACERX_TRACE_PERFORMANCE. +// If this key is 1 or "true" performance output will be written to the same output +// as the tracing output. package tracerx import ( @@ -24,6 +27,7 @@ import ( "strconv" "strings" "sync" + "time" ) var ( @@ -34,8 +38,9 @@ var ( ) type tracer struct { - enabled bool - w io.Writer + enabled bool + performance bool + w io.Writer } // Printf writes a trace message for the DefaultKey @@ -45,19 +50,30 @@ func Printf(format string, args ...interface{}) { // PrintfKey writes a trace message for the given key func PrintfKey(key, format string, args ...interface{}) { - uppedKey := strings.ToUpper(key) - - tracer, ok := tracers[uppedKey] - if !ok { - tracer = initializeTracer(uppedKey) - } - + tracer := getTracer(key) if tracer.enabled { fmt.Fprintf(tracer.w, Prefix+format+"\n", args...) return } } +// PerformanceSince writes out the time since the given time, if +// tracing for the default key is enabled and the performance key is set +func PerformanceSince(what string, t time.Time) { + PerformanceSinceKey(DefaultKey, what, t) +} + +// PerformanceSince writes out the time since the given time, if +// tracing for the given key is enabled and the performance key is set +func PerformanceSinceKey(key, what string, t time.Time) { + tracer := getTracer(key) + + if tracer.enabled && tracer.performance { + since := time.Since(t) + fmt.Fprintf(tracer.w, "performance %s: %.9f s\n", what, since.Seconds()) + } +} + // Disable will disable tracing for the given key, regardless of // the environment variable func Disable(key string) { @@ -76,15 +92,24 @@ func Enable(key string) { } } +func getTracer(key string) *tracer { + uppedKey := strings.ToUpper(key) + tracer, ok := tracers[uppedKey] + if !ok { + tracer = initializeTracer(uppedKey) + } + return tracer +} + func initializeTracer(key string) *tracer { tracerLock.Lock() defer tracerLock.Unlock() if tracer, ok := tracers[key]; ok { - return tracer + return tracer // Someone else initialized while we were blocked } - tracer := &tracer{false, os.Stderr} + tracer := &tracer{false, false, os.Stderr} tracers[key] = tracer trace := os.Getenv(fmt.Sprintf("%s_TRACE", key)) @@ -92,6 +117,11 @@ func initializeTracer(key string) *tracer { return tracer } + perf := os.Getenv(fmt.Sprintf("%s_TRACE_PERFORMANCE", key)) + if perf == "1" || strings.ToLower(perf) == "true" { + tracer.performance = true + } + fd, err := strconv.Atoi(trace) if err != nil { // Not a number, it could be a path for a log file diff --git a/Godeps b/Godeps index 39fc6213..3c9360ac 100644 --- a/Godeps +++ b/Godeps @@ -6,4 +6,4 @@ github.com/olekukonko/ts ecf753e7c962639ab5a1fb46f7da627d4c github.com/spf13/cobra 864687ae689edc28688c67edef47e3d2ad651a1b github.com/spf13/pflag 463bdc838f2b35e9307e91d480878bda5fff7232 github.com/technoweenie/go-contentaddressable 38171def3cd15e3b76eb156219b3d48704643899 -github.com/rubyist/tracerx ecd28355a866ec2378f6df7d7cbf231141720e13 +github.com/rubyist/tracerx b869498bff1ad54bb2df3b98d11f3b6dcefbddc6 diff --git a/scanner/scanner.go b/scanner/scanner.go index d1340c4e..9cf998f9 100644 --- a/scanner/scanner.go +++ b/scanner/scanner.go @@ -4,7 +4,9 @@ import ( "bytes" "github.com/github/git-media/git" "github.com/github/git-media/pointer" + "github.com/rubyist/tracerx" "strconv" + "time" ) type ScannedPointer struct { @@ -17,14 +19,19 @@ func Scan(ref string) ([]*ScannedPointer, error) { // Gets all objects git knows about var buf bytes.Buffer + t := time.Now() objects, _ := git.RevListObjects(ref, "", ref == "") + tracerx.PerformanceSince("rev-list --objects", t) + for _, o := range objects { fileNameMap[o.Sha1] = o.Name buf.WriteString(o.Sha1 + "\n") } // Get type and size info for all objects + t = time.Now() objects, _ = git.CatFileBatchCheck(&buf) + tracerx.PerformanceSince("cat-file --batch-check", t) // Pull out git objects that are type blob and size < 200 bytes. // These are the likely git media pointer files @@ -40,11 +47,14 @@ func Scan(ref string) ([]*ScannedPointer, error) { // // // This string contains all the data, so we parse it out below + t = time.Now() data, _ := git.CatFileBatch(&mediaObjects) + tracerx.PerformanceSince("cat-file --batch", t) r := bytes.NewBufferString(data) pointers := make([]*ScannedPointer, 0) + t = time.Now() for { l, err := r.ReadBytes('\n') if err != nil { // Probably check for EOF @@ -73,5 +83,6 @@ func Scan(ref string) ([]*ScannedPointer, error) { break } } + tracerx.PerformanceSince("decode pointers", t) return pointers, nil }