split

README.md

@@ -2,9 +2,7 @@
 
 To visualize what BOSH is busy doing during a task.
 
-It's taking an after-the-fact approach at profiling by reading the debug logs and pretending it knows what BOSH was thinking while it happened. You probably shouldn't fully trust the accuracy of the results.
-
-alpha/experiment/buggy/use-at-your-own-risk
+It's taking an after-the-fact approach at profiling by reading logs and pretending it knows what BOSH was thinking while it happened. You probably shouldn't fully trust the accuracy of the results.
 
 
 ## Quick Start
@@ -29,6 +27,19 @@ Provide the debug log of a deploy task via `STDIN`...
 Open the URL it prints (something like http://localhost:16686/trace/1cfa67194cc4d8ef).
 
 
+## Caveats
+
+alpha/experiment/buggy/use-at-your-own-risk; also:
+
+ * alpha (pre-alpha?)
+ * experiment / proof of concept; worth pursuing more? get in touch
+ * currently only works with deploy tasks
+ * not tested with failed tasks
+ * not tested across diverse environments
+ * don't expect the code to easily make sense right now
+ * relevant log lines are included in traces and may include sensitive data
+
+
 ## Screenshot
 
 ![Screenshot](docs/example.png)

cmd/taskdebugdebug/main.go

@@ -5,15 +5,11 @@ import (
 	"os"
 
 	"github.com/dpb587/bosh-log-tracer/log"
-	"github.com/dpb587/bosh-log-tracer/log/taskdebug"
+	"github.com/dpb587/bosh-log-tracer/log/taskdebug/parser"
 	"github.com/dpb587/bosh-log-tracer/observer/debug"
 )
 
 func main() {
-	var err error
-
-	parsers := taskdebug.Parser
-
 	observer := debug.NewObserver()
 	observer.Begin()
 	defer observer.Commit()
@@ -31,14 +27,12 @@ func main() {
 			RawLineData:   scanner.Text(),
 		}
 
-		for _, p := range parsers {
-			l, err = p.Parse(l)
-			if err != nil {
-				panic(err)
-			}
+		l, err := parser.Parser.Parse(l)
+		if err != nil {
+			panic(err)
 		}
 
-		err := observer.Handle(l)
+		err = observer.Handle(l)
 		if err != nil {
 			panic(err)
 		}

cmd/taskdebugjaeger/main.go

@@ -5,16 +5,13 @@ import (
 	"os"
 
 	"github.com/dpb587/bosh-log-tracer/log"
-	"github.com/dpb587/bosh-log-tracer/log/taskdebug"
 	"github.com/dpb587/bosh-log-tracer/log/taskdebug/jaeger"
+	"github.com/dpb587/bosh-log-tracer/log/taskdebug/parser"
 	"github.com/dpb587/bosh-log-tracer/observer/context"
 )
 
 func main() {
-	var err error
-
 	ctx := &context.Context{}
-	parsers := taskdebug.Parser
 
 	observer := jaeger.NewObserver(ctx, jaeger.ObserverOptions{
 		IncludeLogReferences: true,
@@ -35,14 +32,12 @@ func main() {
 			RawLineData:   scanner.Text(),
 		}
 
-		for _, p := range parsers {
-			l, err = p.Parse(l)
-			if err != nil {
-				panic(err)
-			}
+		l, err := parser.Parser.Parse(l)
+		if err != nil {
+			panic(err)
 		}
 
-		err := observer.Handle(l)
+		err = observer.Handle(l)
 		if err != nil {
 			panic(err)
 		}

log/multi.go

@@ -0,0 +1,28 @@
+package log
+
+type multiParser struct {
+	parsers []LineParser
+}
+
+var _ LineParser = &multiParser{}
+
+func NewMultiParser(parsers ...LineParser) LineParser {
+	return &multiParser{
+		parsers: parsers,
+	}
+}
+
+func (lp multiParser) Parse(in Line) (Line, error) {
+	var err error
+
+	out := in
+
+	for _, p := range lp.parsers {
+		out, err = p.Parse(out)
+		if err != nil {
+			return nil, err
+		}
+	}
+
+	return out, nil
+}

log/taskdebug/cpi_aws_rpc.go

@@ -1,18 +1,11 @@
 package taskdebug
 
 import (
-	"regexp"
-	"strconv"
-	"strings"
 	"time"
 
 	"github.com/dpb587/bosh-log-tracer/log"
 )
 
-var CPIAWSRPCParser = cpiAWSRPCParser{}
-
-type cpiAWSRPCParser struct{}
-
 type CPIAWSRPCMessage struct {
 	RawMessage
 
@@ -24,42 +17,4 @@ type CPIAWSRPCMessage struct {
 	PayloadMethod string
 }
 
-// [Aws::EC2::Client 200 1.069542 0 retries] run_instances(...
-var cpiAWSRPCOneRE = regexp.MustCompile(`^\[Aws::EC2::Client (\d+) ([\d\.]+) (\d) retries\] (.+)$`)
-
-func (p cpiAWSRPCParser) Parse(inU log.Line) (log.Line, error) {
-	in, ok := inU.(RawMessage)
-	if !ok {
-		return inU, nil
-	}
-
-	if in.Component != "ExternalCpiLog" {
-		return inU, nil
-	}
-
-	if m := cpiAWSRPCOneRE.FindStringSubmatch(in.Message); len(m) > 0 {
-		out := CPIAWSRPCMessage{
-			RawMessage:  in,
-			Correlation: in.Tags["req_id"],
-			Payload:     m[4],
-		}
-
-		out.PayloadMethod = strings.SplitN(out.Payload, "(", 2)[0]
-
-		if res, err := strconv.ParseFloat(m[2], 64); err == nil {
-			out.Duration = time.Duration(int64(res * 1000000))
-		}
-
-		if res, err := strconv.Atoi(m[1]); err == nil {
-			out.StatusCode = res
-		}
-
-		if res, err := strconv.Atoi(m[3]); err == nil {
-			out.Retries = res
-		}
-
-		return out, nil
-	}
-
-	return inU, nil
-}
+var _ log.Line = &CPIAWSRPCMessage{}

log/taskdebug/external_cpi.go

@@ -1,14 +1,6 @@
 package taskdebug
 
-import (
-	"regexp"
-
-	"github.com/dpb587/bosh-log-tracer/log"
-)
-
-var ExternalCPIParser = externalCPIParser{}
-
-type externalCPIParser struct{}
+import "github.com/dpb587/bosh-log-tracer/log"
 
 type ExternalCPIMessage struct {
 	RawMessage
@@ -18,29 +10,4 @@ type ExternalCPIMessage struct {
 	Remaining   string
 }
 
-// [external-cpi] [cpi-308955] request: {"method":"create_vm","arguments":[...
-var externalCPIOneRE = regexp.MustCompile(`^\[external-cpi\] \[(cpi-\d+)\] (request|response): (.+)$`)
-
-func (p externalCPIParser) Parse(inU log.Line) (log.Line, error) {
-	in, ok := inU.(RawMessage)
-	if !ok {
-		return inU, nil
-	}
-
-	if in.Component != "DirectorJobRunner" {
-		return inU, nil
-	}
-
-	if m := externalCPIOneRE.FindStringSubmatch(in.Message); len(m) > 0 {
-		out := ExternalCPIMessage{
-			RawMessage:  in,
-			Correlation: m[1],
-			Event:       m[2],
-			Remaining:   m[3],
-		}
-
-		return out, nil
-	}
-
-	return inU, nil
-}
+var _ log.Line = &ExternalCPIMessage{}

log/taskdebug/external_cpi_request.go

@@ -1,15 +1,6 @@
 package taskdebug
 
-import (
-	"encoding/json"
-	"regexp"
-
-	"github.com/dpb587/bosh-log-tracer/log"
-)
-
-var ExternalCPIRequestParser = externalCPIRequestParser{}
-
-type externalCPIRequestParser struct{}
+import "github.com/dpb587/bosh-log-tracer/log"
 
 type ExternalCPIRequestMessage struct {
 	ExternalCPIMessage
@@ -19,51 +10,4 @@ type ExternalCPIRequestMessage struct {
 	Command       string
 }
 
-// [external-cpi] [cpi-308955] request: {"method":"create_vm","arguments":[...
-var externalCPIRequestOneRE = regexp.MustCompile(`(\{.+\}) with command: (.+)$`)
-
-func (p externalCPIRequestParser) Parse(inU log.Line) (log.Line, error) {
-	inU, err := ExternalCPIParser.Parse(inU)
-	if inU == nil || err != nil {
-		return inU, err
-	}
-
-	in, ok := inU.(ExternalCPIMessage)
-	if !ok {
-		return inU, nil
-	}
-
-	upstreamU, err := ExternalCPIParser.Parse(in)
-	if upstreamU == nil || err != nil {
-		return upstreamU, err
-	}
-
-	upstream := upstreamU.(ExternalCPIMessage)
-
-	if upstream.Event != "request" {
-		return upstream, nil
-	}
-
-	if m := externalCPIRequestOneRE.FindStringSubmatch(upstream.Remaining); len(m) > 0 {
-		out := ExternalCPIRequestMessage{
-			ExternalCPIMessage: upstream,
-			Payload: m[1],
-			Command:            m[2],
-		}
-
-		var payload struct {
-			Method string `json:"method"`
-		}
-
-		err = json.Unmarshal([]byte(out.Payload), &payload)
-		if err != nil {
-			panic(err)
-		}
-
-		out.PayloadMethod = payload.Method
-
-		return out, nil
-	}
-
-	return upstreamU, nil
-}
+var _ log.Line = &ExternalCPIRequestMessage{}

log/taskdebug/instance_aspect_changed.go

@@ -3,16 +3,11 @@ package taskdebug
 import (
 	"encoding/json"
 	"fmt"
-	"regexp"
 	"strings"
 
 	"github.com/dpb587/bosh-log-tracer/log"
 )
 
-var InstanceAspectChangedParser = instanceAspectChangedParser{}
-
-type instanceAspectChangedParser struct{}
-
 type InstanceAspectChangedMessage struct {
 	RawMessage
 
@@ -24,6 +19,8 @@ type InstanceAspectChangedMessage struct {
 	ChangedTo     string
 }
 
+var _ log.Line = &InstanceAspectChangedMessage{}
+
 type packageChangeSet map[string]struct {
 	Name        string `json:"name"`
 	Version     string `json:"version"`
@@ -73,35 +70,3 @@ func (m InstanceAspectChangedMessage) GetChangedPackages() []string {
 
 	return res
 }
-
-var _ log.Line = &InstanceAspectChangedMessage{}
-
-// stemcell_changed? changed FROM: version: 315.36 TO: version: 315.41 on instance concourse/6318b9e7-8c72-4c4e-8769-e59abaa32297 (0)
-var instanceAspectChangedOneRE = regexp.MustCompile(`^(.+)_changed\? changed FROM: (.+) TO: (.+) on instance ([^/]+)/([^ ]+) \((\d+)\)$`)
-
-func (p instanceAspectChangedParser) Parse(inU log.Line) (log.Line, error) {
-	in, ok := inU.(RawMessage)
-	if !ok {
-		return inU, nil
-	}
-
-	if in.Component != "DirectorJobRunner" {
-		return inU, nil
-	}
-
-	if m := instanceAspectChangedOneRE.FindStringSubmatch(in.Message); len(m) > 0 {
-		msg := InstanceAspectChangedMessage{
-			RawMessage:    in,
-			InstanceGroup: m[4],
-			InstanceID:    m[5],
-			InstanceIndex: m[6],
-			Aspect:        m[1],
-			ChangedFrom:   m[2],
-			ChangedTo:     m[3],
-		}
-
-		return msg, nil
-	}
-
-	return inU, nil
-}