[symbolize] Add better backtrace formatting
This change adds a new backtrace formatter that intercepts lone
backtrace lines and prints them out on multiple lines with all
information we've thusfar determined would be nice. inlines are
printed out on seperate lines in the same format with a special
inline number.
TC-174
Change-Id: Ia0afe2deefad5615dc82afd473f9ecf1830f3447
diff --git a/cmd/symbolize/main.go b/cmd/symbolize/main.go
index 5f54a8c..2636bf0 100644
--- a/cmd/symbolize/main.go
+++ b/cmd/symbolize/main.go
@@ -114,7 +114,7 @@
tap,
&symbolize.FilterContextElements{},
&symbolize.OptimizeColor{},
- presenter)
+ symbolize.NewBacktracePresenter(os.Stdout, presenter))
symbolize.Consume(trash)
// Once the pipeline has finished output all triggers
diff --git a/symbolize/demuxer_test.go b/symbolize/demuxer_test.go
index 2bb3dd0..b703299 100644
--- a/symbolize/demuxer_test.go
+++ b/symbolize/demuxer_test.go
@@ -195,7 +195,7 @@
}},
})
- // mock ids.txt:q
+ // mock ids.txt
repo := NewRepo()
repo.AddSource(testBinaries)
@@ -223,6 +223,56 @@
//[131.604] 01234.05678> Error at atan2 at atan2.c:49
}
+func ExampleNewBacktracePresenter() {
+ // mock the input and outputs of llvm-symbolizer
+ symbo := newMockSymbolizer([]mockModule{
+ {"testdata/libc.elf", map[uint64][]SourceLocation{
+ 0x429c0: {{NewOptStr("atan2.c"), 49, NewOptStr("atan2")}, {NewOptStr("math.h"), 51, NewOptStr("__DOUBLE_FLOAT")}},
+ 0x43680: {{NewOptStr("pow.c"), 23, NewOptStr("pow")}},
+ 0x44987: {{NewOptStr("memcpy.c"), 76, NewOptStr("memcpy")}},
+ }},
+ {"testdata/libcrypto.elf", map[uint64][]SourceLocation{
+ 0x81000: {{NewOptStr("rsa.c"), 101, NewOptStr("mod_exp")}},
+ 0x82000: {{NewOptStr("aes.c"), 17, NewOptStr("gf256_mul")}},
+ 0x83000: {{NewOptStr("aes.c"), 560, NewOptStr("gf256_div")}},
+ }},
+ })
+
+ // mock ids.txt
+ repo := NewRepo()
+ repo.AddSource(testBinaries)
+
+ // make a demuxer
+ demuxer := NewDemuxer(repo, symbo)
+
+ // define a little message that will need to be parsed
+ msg := "[131.200] 1234.5678> {{{module:1:libc.so:elf:4fcb712aa6387724a9f465a32cd8c14b}}}\n" +
+ "[131.301] 1234.5678> {{{module:2:libcrypto.so:elf:12ef5c50b3ed3599c07c02d4509311be}}}\n" +
+ "[131.402] 1234.5678> {{{mmap:0x12345000:0xcf6bc:load:1:rx:0x0}}}\n" +
+ "[131.503] 1234.5678> {{{mmap:0x23456000:0x83c80:load:2:rx:0x80000}}}\n" +
+ "[131.604] 1234.5678> Backtrace:\n" +
+ "[131.604] 1234.5678> {{{bt:0:0x12388680}}}\n" +
+ "[131.604] 1234.5678> {{{bt:1:0x23457000}}}\n" +
+ "[131.604] 1234.5678> {{{bt:2:0x123879c0}}}\n"
+
+ // start sending InputLines to the demuxer
+ ctx := context.Background()
+ in := StartParsing(ctx, strings.NewReader(msg))
+ // start the demuxer which will cause filters to send output lines to 'out'
+ out := demuxer.Start(ctx, in)
+
+ Consume(ComposePostProcessors(ctx, out,
+ &FilterContextElements{},
+ NewBacktracePresenter(os.Stdout, NewBasicPresenter(os.Stdout, false))))
+
+ //Output:
+ //[131.604] 01234.05678> Backtrace:
+ //[131.604] 01234.05678> #0 0x0000000012388680 in pow pow.c:23 <libc.so>+0x43680
+ //[131.604] 01234.05678> #1 0x0000000023457000 in mod_exp rsa.c:101 <libcrypto.so>+0x81000
+ //[131.604] 01234.05678> #2.1 0x00000000123879c0 in __DOUBLE_FLOAT math.h:51 <libc.so>+0x429c0
+ //[131.604] 01234.05678> #2 0x00000000123879c0 in atan2 atan2.c:49 <libc.so>+0x429c0
+}
+
func ExampleBadAddr() {
// mock the input and outputs of llvm-symbolizer
symbo := newMockSymbolizer([]mockModule{
diff --git a/symbolize/filter.go b/symbolize/filter.go
index f781dda..c442f07 100644
--- a/symbolize/filter.go
+++ b/symbolize/filter.go
@@ -21,7 +21,9 @@
type DummySource struct{}
-type lineHeader interface{}
+type LineHeader interface {
+ Present() string
+}
type logHeader struct {
time float64
@@ -29,6 +31,10 @@
thread uint64
}
+func (l logHeader) Present() string {
+ return fmt.Sprintf("[%.3f] %05d.%05d>", l.time, l.process, l.thread)
+}
+
type sysLogHeader struct {
time float64
process uint64
@@ -36,9 +42,13 @@
tags string
}
+func (s sysLogHeader) Present() string {
+ return fmt.Sprintf("[%012.6f][%d][%d][%s]", s.time, s.process, s.thread, s.tags)
+}
+
type LogLine struct {
lineno uint64
- header lineHeader
+ header LineHeader
source LineSource
}
diff --git a/symbolize/presenter.go b/symbolize/presenter.go
index e59efbd..36006d9 100644
--- a/symbolize/presenter.go
+++ b/symbolize/presenter.go
@@ -9,6 +9,58 @@
"io"
)
+// BacktracePresenter intercepts backtrace elements on their own line and
+// presents them in text. Inlines are output as separate lines.
+// A PostProcessor is taken as an input to synchronously compose another
+// PostProcessor
+type BacktracePresenter struct {
+ out io.Writer
+ next PostProcessor
+}
+
+// NewBacktracePresenter constructs a BacktracePresenter.
+func NewBacktracePresenter(out io.Writer, next PostProcessor) *BacktracePresenter {
+ return &BacktracePresenter{
+ out: out,
+ next: next,
+ }
+}
+
+func printBacktrace(out io.Writer, hdr LineHeader, frame uint64, info addressInfo) {
+ for i, _ := range info.locs {
+ i = len(info.locs) - i - 1
+ loc := info.locs[i]
+ fmt.Fprintf(out, "%s ", hdr.Present())
+ var frameStr string
+ if i == 0 {
+ frameStr = fmt.Sprintf("#%d", frame)
+ } else {
+ frameStr = fmt.Sprintf("#%d.%d", frame, i)
+ }
+ fmt.Fprintf(out, "%-5s", frameStr)
+ fmt.Fprintf(out, " %#016x", info.addr)
+ if !loc.function.IsEmpty() {
+ fmt.Fprintf(out, " in %v", loc.function)
+ }
+ modRelAddr := info.addr - info.seg.Vaddr + info.seg.ModRelAddr
+ if !loc.file.IsEmpty() {
+ fmt.Fprintf(out, " %s:%d", loc.file, loc.line)
+ }
+ fmt.Fprintf(out, " <%s>+%#x\n", info.mod.Name, modRelAddr)
+ }
+}
+
+func (b *BacktracePresenter) Process(line OutputLine, out chan<- OutputLine) {
+ if len(line.line) == 1 {
+ if bt, ok := line.line[0].(*BacktraceElement); ok {
+ printBacktrace(b.out, line.header, bt.num, bt.info)
+ // Don't process a backtrace we've already output.
+ return
+ }
+ }
+ b.next.Process(line, out)
+}
+
// FilterContextElements filters out lines that only contain contextual
// elements and colors.
type FilterContextElements struct {
@@ -103,13 +155,8 @@
}
func (b *BasicPresenter) Process(res OutputLine, out chan<- OutputLine) {
- // TODO (jakehehrlich): Make the header interface have a ToString method and use
- // that instead
- if hdr, ok := res.header.(logHeader); ok {
- fmt.Fprintf(b.output, "[%.3f] %05d.%05d> ", hdr.time, hdr.process, hdr.thread)
- }
- if hdr, ok := res.header.(sysLogHeader); ok {
- fmt.Fprintf(b.output, "[%012.6f][%d][%d][%s] ", hdr.time, hdr.process, hdr.thread, hdr.tags)
+ if res.header != nil {
+ fmt.Fprintf(b.output, "%s ", res.header.Present())
}
for _, token := range res.line {
switch node := token.(type) {
