search

brimdata / super

A novel data lake based on super-structured data
https://zed.brimdata.io/
BSD 3-Clause "New" or "Revised" License
1.39k stars 64 forks source link

Text stack traces should not show up in an ZJSON response stream #1098

Closed philrz closed 4 years ago

philrz commented 4 years ago

Beyond the specific issue fixed in #1087, the team was surprised by the fact that the text stack trace appeared in the middle of the ZJSON response.

To repro, run Brim at commit 8c496e0 and import the pcap wrccdc.2018-03-23.010014000000000.pcap.gz. As captured in #1087, sniffing the traffic in Wireshark reveals responses like:

{"type":"TaskStart","task_id":0}

{"type":"TaskEnd","task_id":0}
panic: runtime error: slice bounds out of range [17:15]
goroutine 72 [running]:
runtime/debug.Stack(0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.14.5/libexec/src/runtime/debug/stack.go:24 +0x9d
github.com/brimsec/zq/zqe.RecoverError(0x1b31420, 0xc000039040, 0x5, 0xc0005ae080)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqe/error.go:124 +0x26
github.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1(0xc0001e66c0, 0x1e3e180, 0xc0006f2200)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/middleware.go:81 +0x1da
panic(0x1b31420, 0xc000039040)
    /usr/local/Cellar/go/1.14.5/libexec/src/runtime/panic.go:969 +0x166
github.com/brimsec/zq/zcode.(*Iter).Next(0xc00048ce10, 0xc0008cc100, 0x2, 0x2, 0x3, 0xc0005ae040, 0x2)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zcode/iter.go:31 +0x22c
github.com/brimsec/zq/zio/zjsonio.encodeContainer(0x1e47e40, 0xc000744b40, 0xc00049c002, 0x30, 0x3fc0, 0x1f40, 0xc0005aa000, 0xc00048cfb0, 0x1)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zio/zjsonio/stream.go:100 +0x174
github.com/brimsec/zq/zio/zjsonio.(*Stream).Transform(0xc0008a8160, 0xc0003e25c0, 0x64, 0xc0005aa000, 0x1e47940)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zio/zjsonio/stream.go:32 +0xf3
github.com/brimsec/zq/zqd/search.(*JSON).formatRecords(0xc0006f2320, 0xc0004aa000, 0x64, 0x100, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/search/json.go:32 +0x88
github.com/brimsec/zq/zqd/search.(*JSON).SendBatch(0xc0006f2320, 0x0, 0x1e47940, 0xc0006f28a0, 0x0, 0x0)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/search/json.go:49 +0xe1
github.com/brimsec/zq/zqd/search.(*searchdriver).Write(0xc0006f2340, 0x0, 0x1e47940, 0xc0006f28a0, 0x0, 0x0)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/search/search.go:144 +0x51
github.com/brimsec/zq/driver.runMux(0xc0000a02d0, 0x1e43f40, 0xc0006f2340, 0xc000200b40, 0xc00037a310, 0x3591370)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/driver/driver.go:59 +0x253
github.com/brimsec/zq/driver.Run(0x1e43b80, 0xc0003e2240, 0x1e43f40, 0xc0006f2340, 0x1e2c620, 0xc000744540, 0xc00037a310, 0x3591370, 0xc000250370, 0x0, ...)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/driver/driver.go:30 +0x17f
github.com/brimsec/zq/zqd/search.(*SearchOp).Run(0xc000472040, 0x1e43b80, 0xc0003e2240, 0x3591188, 0xc0003a3440, 0x1e43ec0, 0xc0006f2320, 0x0, 0x0)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/search/search.go:84 +0x384
github.com/brimsec/zq/zqd.handleSearch(0xc0004304b0, 0x1e3e180, 0xc0006f2200, 0xc0008e2300)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/handlers.go:109 +0x3f9
github.com/brimsec/zq/zqd.(*handler).Handle.func1(0x1e3e180, 0xc0006f2200, 0xc0008e2300)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/handler.go:21 +0x50
net/http.HandlerFunc.ServeHTTP(0xc00042d100, 0x1e3e180, 0xc0006f2200, 0xc0008e2300)
    /usr/local/Cellar/go/1.14.5/libexec/src/net/http/server.go:2041 +0x44
github.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1(0x1e3e180, 0xc0006f2200, 0xc0008e2300)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/middleware.go:85 +0x87
net/http.HandlerFunc.ServeHTTP(0xc0006f2060, 0x1e3e180, 0xc0006f2200, 0xc0008e2300)
    /usr/local/Cellar/go/1.14.5/libexec/src/net/http/server.go:2041 +0x44
github.com/brimsec/zq/zqd.accessLogMiddleware.func1.1(0x1e3f840, 0xc0001ba460, 0xc0008e2300)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/middleware.go:67 +0x925
net/http.HandlerFunc.ServeHTTP(0xc0006f2080, 0x1e3f840, 0xc0001ba460, 0xc0008e2300)
    /usr/local/Cellar/go/1.14.5/libexec/src/net/http/server.go:2041 +0x44
github.com/brimsec/zq/zqd.requestIDMiddleware.func1.1(0x1e3f840, 0xc0001ba460, 0xc0008e2200)
    /Users/alfred/.npm/_cacache/tmp/git-clone-5dac50cd/zqd/middleware.go:38 +0x2a1
net/http.HandlerFunc.ServeHTTP(0xc0006f20a0, 0x1e3f840, 0xc0001ba460, 0xc0008e2200)
    /usr/local/Cellar/go/1.14.5/libexec/src/net/http/server.go:2041 +0x44
github.com/gorilla/mux.(*Router).ServeHTTP(0xc00042a180, 0x1e3f840, 0xc0001ba460, 0xc0008e2000)
    /Users/alfred/src/go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210 +0xe2
net/http.serverHandler.ServeHTTP(0xc0001ba2a0, 0x1e3f840, 0xc0001ba460, 0xc0008e2000)
    /usr/local/Cellar/go/1.14.5/libexec/src/net/http/server.go:2836 +0xa3
net/http.(*conn).serve(0xc00014b220, 0x1e43b80, 0xc0003e2000)
    /usr/local/Cellar/go/1.14.5/libexec/src/net/http/server.go:1924 +0x86c
created by net/http.(*Server).Serve
    /usr/local/Cellar/go/1.14.5/libexec/src/net/http/server.go:2962 +0x35c

As of that commit, this resulted in the opaque error message in Brim Unexpected token p in JSON at position 31 which does not help the user understand what went wrong and it would not be very helpful if reported to us by a user asking for Support assistance. Some ways to possible handle this better:

  1. Turn the stack trace info valid NDJSON such that it could be identified by the client and presented to the user in a way that it could be cut & pasted to us as part of a Support interaction.

  2. Spare the user from seeing the stack trace, but give a more friendly/brief error response, while the full stack trace goes to the zqd logs (#1097). There's a wiki article that talks about where to find those zqd logs, so perhaps an improved error response could link to that so the user could immediately move on to zipping those up and including them in a bug report.

philrz commented 4 years ago

Verified in Brim commit 8c496e0 with a custom zqd.

Specifically, I started from zq commit 1b14385 that was the original commit pointer in package.json for Brim commit 8c496e0 where #1087 was first reproduced. I then did a git cherry-pick of zq commits dc7403b and 7ff4135 that made up the commits of the PR #1166 linked to this issue, then compiled that zqd and put it in the zdeps/ directory so it would be launched when my Brim starts. With this combination, I expected to still be able to trigger the panic that caused the stack trace, but the fix should prevent the stack trace from leaking out in the NDJSON response.

As shown in the attached video (sped up 4x for file size reasons), with this combination, while the "Malformed zng value" error message still appears in Brim (not the issue of concern here) we no longer see the "Unexpected token p in JSON at position 31" error that was indicative of the leaked stack trace in the NDJSON.

Verify.mp4.zip

Also, the stack trace is showing up in the zqd log now. Here's what it looked like before where only the "headline" of the stack trace was showing up there:

{"level":"info","ts":1598310404.1681302,"msg":"Starting","datadir":"/Users/phil/work/brim/run/data/spaces","pprof_routes":false,"zeek_supported":true}
{"level":"info","ts":1598310404.170559,"logger":"httpd","msg":"Listening","addr":"127.0.0.1:9867"}
{"level":"warn","ts":1598310419.684445,"msg":"Error writing response","request_id":"6","error":"malformed zng value"}
{"level":"dpanic","ts":1598310422.669783,"msg":"Panic","error":"runtime error: slice bounds out of range [663:8]"}
{"level":"warn","ts":1598310425.80725,"msg":"Error writing response","request_id":"13","error":"malformed zng value"}
{"level":"warn","ts":1598310425.914876,"msg":"Error writing response","request_id":"16","error":"malformed zng value"}
{"level":"dpanic","ts":1598310434.602037,"msg":"Panic","error":"runtime error: slice bounds out of range [15:6]"}
{"level":"dpanic","ts":1598310451.7395809,"msg":"Panic","error":"runtime error: slice bounds out of range [123:86]"}
{"level":"dpanic","ts":1598310456.478091,"msg":"Panic","error":"runtime error: slice bounds out of range [17:15]"}

Now we see:

{"level":"info","ts":1598311033.197866,"msg":"Starting","datadir":"/Users/phil/work/brim/run/data/spaces","pprof_routes":false,"zeek_supported":true}
{"level":"info","ts":1598311033.201347,"logger":"httpd","msg":"Listening","addr":"127.0.0.1:9867"}
{"level":"dpanic","ts":1598311070.2527812,"msg":"Panic","error":"panic: runtime error: slice bounds out of range [51:39]\ngoroutine 63 [running]:\nruntime/debug.Stack(0xc0004ce000, 0xc0004d1000, 0x25)\n\t/usr/local/opt/go/libexec/src/runtime/debug/stack.go:24 +0x9d\ngithub.com/brimsec/zq/zqe.RecoverError(0x1b30fa0, 0xc001054760, 0xc001054760, 0x2af7f60)\n\t/Users/phil/work/zq/zqe/error.go:124 +0x26\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1(0xc000200540, 0xc00021fa00)\n\t/Users/phil/work/zq/zqd/middleware.go:80 +0x64\npanic(0x1b30fa0, 0xc001054760)\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967 +0x15d\ngithub.com/brimsec/zq/zcode.(*Iter).Next(0xc000f0ee18, 0x2af7e40, 0xc000f36095, 0x3, 0x3f0e, 0x1a0ba60, 0xc001056470)\n\t/Users/phil/work/zq/zcode/iter.go:31 +0x22c\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer(0x1e47c60, 0xc000f106c0, 0xc000f36003, 0xbc, 0x3fa0, 0x16d0, 0xc00011d800, 0xc000f0efb8, 0x1065a00)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:100 +0x174\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform(0xc00042dcc0, 0xc000f32d80, 0x49, 0xc00011d800, 0x1e47760)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32 +0xf3\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords(0xc000cb8d60, 0xc00022d800, 0x49, 0x80, 0x0, 0x0, 0x0, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:32 +0x88\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch(0xc000cb8d60, 0x0, 0x1e47760, 0xc000cb9320, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:49 +0xe1\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write(0xc000cb8d80, 0x0, 0x1e47760, 0xc000cb9320, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:144 +0x51\ngithub.com/brimsec/zq/driver.runMux(0xc00012c870, 0x1e43d20, 0xc000cb8d80, 0xc000c9b2c0, 0xc0001a78f0, 0xac442f0)\n\t/Users/phil/work/zq/driver/driver.go:59 +0x253\ngithub.com/brimsec/zq/driver.Run(0x1e43960, 0xc000c7fe00, 0x1e43d20, 0xc000cb8d80, 0x1e2c440, 0xc000f10060, 0xc0001a78f0, 0xac442f0, 0xc0000fd6b0, 0x0, ...)\n\t/Users/phil/work/zq/driver/driver.go:30 +0x17f\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run(0xc000010538, 0x1e43960, 0xc000c7fe00, 0xac44188, 0xc0000f8500, 0x1e43ca0, 0xc000cb8d60, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:84 +0x384\ngithub.com/brimsec/zq/zqd.handleSearch(0xc000202510, 0x1e3df60, 0xc000cb8c00, 0xc00021fa00)\n\t/Users/phil/work/zq/zqd/handlers.go:109 +0x3f9\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1(0x1e3df60, 0xc000cb8c00, 0xc00021fa00)\n\t/Users/phil/work/zq/zqd/handler.go:21 +0x50\nnet/http.HandlerFunc.ServeHTTP(0xc000204f80, 0x1e3df60, 0xc000cb8c00, 0xc00021fa00)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1(0x1e3df60, 0xc000cb8c00, 0xc00021fa00)\n\t/Users/phil/work/zq/zqd/middleware.go:86 +0x82\nnet/http.HandlerFunc.ServeHTTP(0xc000cb8a80, 0x1e3df60, 0xc000cb8c00, 0xc00021fa00)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1(0x1e3f620, 0xc0001ca0e0, 0xc00021fa00)\n\t/Users/phil/work/zq/zqd/middleware.go:66 +0x925\nnet/http.HandlerFunc.ServeHTTP(0xc000cb8aa0, 0x1e3f620, 0xc0001ca0e0, 0xc00021fa00)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1(0x1e3f620, 0xc0001ca0e0, 0xc00021f900)\n\t/Users/phil/work/zq/zqd/middleware.go:37 +0x2a1\nnet/http.HandlerFunc.ServeHTTP(0xc000cb8ac0, 0x1e3f620, 0xc0001ca0e0, 0xc00021f900)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000246180, 0x1e3f620, 0xc0001ca0e0, 0xc0004d2000)\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210 +0xe2\nnet/http.serverHandler.ServeHTTP(0xc0001ca380, 0x1e3f620, 0xc0001ca0e0, 0xc0004d2000)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807 +0xa3\nnet/http.(*conn).serve(0xc0001c2820, 0x1e43960, 0xc0004b69c0)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895 +0x86c\ncreated by net/http.(*Server).Serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2933 +0x35c\n\n","request_id":"7","stack":"github.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1\n\t/Users/phil/work/zq/zqd/middleware.go:82\nruntime.gopanic\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967\nruntime.goPanicSliceB\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:116\ngithub.com/brimsec/zq/zcode.(*Iter).Next\n\t/Users/phil/work/zq/zcode/iter.go:31\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:100\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords\n\t/Users/phil/work/zq/zqd/search/json.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch\n\t/Users/phil/work/zq/zqd/search/json.go:49\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write\n\t/Users/phil/work/zq/zqd/search/search.go:144\ngithub.com/brimsec/zq/driver.runMux\n\t/Users/phil/work/zq/driver/driver.go:59\ngithub.com/brimsec/zq/driver.Run\n\t/Users/phil/work/zq/driver/driver.go:30\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run\n\t/Users/phil/work/zq/zqd/search/search.go:84\ngithub.com/brimsec/zq/zqd.handleSearch\n\t/Users/phil/work/zq/zqd/handlers.go:109\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1\n\t/Users/phil/work/zq/zqd/handler.go:21\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:86\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:66\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:37\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807\nnet/http.(*conn).serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895"}
{"level":"warn","ts":1598311073.234766,"msg":"Error writing response","request_id":"12","error":"malformed zng value"}
{"level":"dpanic","ts":1598311076.23691,"msg":"Panic","error":"panic: runtime error: slice bounds out of range [123:75]\ngoroutine 25 [running]:\nruntime/debug.Stack(0xc000185580, 0xc000cf6000, 0x25)\n\t/usr/local/opt/go/libexec/src/runtime/debug/stack.go:24 +0x9d\ngithub.com/brimsec/zq/zqe.RecoverError(0x1b30fa0, 0xc000ea8080, 0xc000ea8080, 0x2af7f60)\n\t/Users/phil/work/zq/zqe/error.go:124 +0x26\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1(0xc000200540, 0xc0003d0100)\n\t/Users/phil/work/zq/zqd/middleware.go:80 +0x64\npanic(0x1b30fa0, 0xc000ea8080)\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967 +0x15d\ngithub.com/brimsec/zq/zcode.(*Iter).Next(0xc00057ee18, 0x2af7e40, 0xc00056e071, 0x3, 0x3f69, 0x1a0ba60, 0xc0003b32e0)\n\t/Users/phil/work/zq/zcode/iter.go:31 +0x22c\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer(0x1e47c60, 0xc00044bfb0, 0xc00056e003, 0xbc, 0x3fd7, 0x1770, 0xc00011d800, 0xc00057efe0, 0x1)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:100 +0x174\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform(0xc0008c72a0, 0xc0004559c0, 0x4b, 0xc00011d800, 0x1e47760)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32 +0xf3\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords(0xc000deade0, 0xc000477c00, 0x4b, 0x80, 0x0, 0x0, 0x0, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:32 +0x88\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch(0xc000deade0, 0x0, 0x1e47760, 0xc000deb240, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:49 +0xe1\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write(0xc000deae00, 0x0, 0x1e47760, 0xc000deb240, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:144 +0x51\ngithub.com/brimsec/zq/driver.runMux(0xc00012c6e0, 0x1e43d20, 0xc000deae00, 0xc000c9b9e0, 0xc0003a9d50, 0xac442f0)\n\t/Users/phil/work/zq/driver/driver.go:59 +0x253\ngithub.com/brimsec/zq/driver.Run(0x1e43960, 0xc000455680, 0x1e43d20, 0xc000deae00, 0x1e2c440, 0xc00044ba10, 0xc0003a9d50, 0xac442f0, 0xc0000fc8f0, 0x0, ...)\n\t/Users/phil/work/zq/driver/driver.go:30 +0x17f\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run(0xc000e04188, 0x1e43960, 0xc000455680, 0xac44188, 0xc0000f8500, 0x1e43ca0, 0xc000deade0, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:84 +0x384\ngithub.com/brimsec/zq/zqd.handleSearch(0xc000202510, 0x1e3df60, 0xc000deace0, 0xc0003d0100)\n\t/Users/phil/work/zq/zqd/handlers.go:109 +0x3f9\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1(0x1e3df60, 0xc000deace0, 0xc0003d0100)\n\t/Users/phil/work/zq/zqd/handler.go:21 +0x50\nnet/http.HandlerFunc.ServeHTTP(0xc000204f80, 0x1e3df60, 0xc000deace0, 0xc0003d0100)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1(0x1e3df60, 0xc000deace0, 0xc0003d0100)\n\t/Users/phil/work/zq/zqd/middleware.go:86 +0x82\nnet/http.HandlerFunc.ServeHTTP(0xc000deab60, 0x1e3df60, 0xc000deace0, 0xc0003d0100)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1(0x1e3f620, 0xc0004620e0, 0xc0003d0100)\n\t/Users/phil/work/zq/zqd/middleware.go:66 +0x925\nnet/http.HandlerFunc.ServeHTTP(0xc000deab80, 0x1e3f620, 0xc0004620e0, 0xc0003d0100)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1(0x1e3f620, 0xc0004620e0, 0xc0003d0000)\n\t/Users/phil/work/zq/zqd/middleware.go:37 +0x2a1\nnet/http.HandlerFunc.ServeHTTP(0xc000deaba0, 0x1e3f620, 0xc0004620e0, 0xc0003d0000)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000246180, 0x1e3f620, 0xc0004620e0, 0xc000f29d00)\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210 +0xe2\nnet/http.serverHandler.ServeHTTP(0xc0001ca380, 0x1e3f620, 0xc0004620e0, 0xc000f29d00)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807 +0xa3\nnet/http.(*conn).serve(0xc0000321e0, 0x1e43960, 0xc000c7f940)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895 +0x86c\ncreated by net/http.(*Server).Serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2933 +0x35c\n\n","request_id":"16","stack":"github.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1\n\t/Users/phil/work/zq/zqd/middleware.go:82\nruntime.gopanic\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967\nruntime.goPanicSliceB\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:116\ngithub.com/brimsec/zq/zcode.(*Iter).Next\n\t/Users/phil/work/zq/zcode/iter.go:31\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:100\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords\n\t/Users/phil/work/zq/zqd/search/json.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch\n\t/Users/phil/work/zq/zqd/search/json.go:49\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write\n\t/Users/phil/work/zq/zqd/search/search.go:144\ngithub.com/brimsec/zq/driver.runMux\n\t/Users/phil/work/zq/driver/driver.go:59\ngithub.com/brimsec/zq/driver.Run\n\t/Users/phil/work/zq/driver/driver.go:30\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run\n\t/Users/phil/work/zq/zqd/search/search.go:84\ngithub.com/brimsec/zq/zqd.handleSearch\n\t/Users/phil/work/zq/zqd/handlers.go:109\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1\n\t/Users/phil/work/zq/zqd/handler.go:21\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:86\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:66\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:37\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807\nnet/http.(*conn).serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895"}
{"level":"dpanic","ts":1598311079.242256,"msg":"Panic","error":"panic: runtime error: slice bounds out of range [16:4]\ngoroutine 25 [running]:\nruntime/debug.Stack(0xc000185580, 0xc000cf6000, 0x25)\n\t/usr/local/opt/go/libexec/src/runtime/debug/stack.go:24 +0x9d\ngithub.com/brimsec/zq/zqe.RecoverError(0x1b30fa0, 0xc001f3ea20, 0xc001f3ea20, 0x2af7f60)\n\t/Users/phil/work/zq/zqe/error.go:124 +0x26\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1(0xc000200540, 0xc000f28800)\n\t/Users/phil/work/zq/zqd/middleware.go:80 +0x64\npanic(0x1b30fa0, 0xc001f3ea20)\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967 +0x15d\ngithub.com/brimsec/zq/zcode.(*Iter).Next(0xc0018d4e18, 0xc0018a8ae0, 0xc001792111, 0xa, 0x3ea7, 0x19f96a0, 0xc001f44900)\n\t/Users/phil/work/zq/zcode/iter.go:31 +0x22c\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer(0x1e47c60, 0xc0018a6e10, 0xc001792003, 0x11c, 0x3fb5, 0x16d0, 0xc00011f000, 0xc0018d4fb8, 0x1065a00)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:100 +0x174\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform(0xc0003b3000, 0xc0018abb80, 0x49, 0xc00011f000, 0x1e47760)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32 +0xf3\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords(0xc0018a8860, 0xc0018e5c00, 0x49, 0x80, 0x0, 0x0, 0x0, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:32 +0x88\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch(0xc0018a8860, 0x0, 0x1e47760, 0xc0018a8c40, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:49 +0xe1\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write(0xc0018a8880, 0x0, 0x1e47760, 0xc0018a8c40, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:144 +0x51\ngithub.com/brimsec/zq/driver.runMux(0xc0000f0780, 0x1e43d20, 0xc0018a8880, 0xc0018ba1e0, 0xc0001940e0, 0xac442f0)\n\t/Users/phil/work/zq/driver/driver.go:59 +0x253\ngithub.com/brimsec/zq/driver.Run(0x1e43960, 0xc0018aa600, 0x1e43d20, 0xc0018a8880, 0x1e2c440, 0xc0018a68d0, 0xc0001940e0, 0xac442f0, 0xc0000fc840, 0x0, ...)\n\t/Users/phil/work/zq/driver/driver.go:30 +0x17f\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run(0xc000208028, 0x1e43960, 0xc0018aa600, 0xac44188, 0xc0000f8500, 0x1e43ca0, 0xc0018a8860, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:84 +0x384\ngithub.com/brimsec/zq/zqd.handleSearch(0xc000202510, 0x1e3df60, 0xc0018a8760, 0xc000f28800)\n\t/Users/phil/work/zq/zqd/handlers.go:109 +0x3f9\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1(0x1e3df60, 0xc0018a8760, 0xc000f28800)\n\t/Users/phil/work/zq/zqd/handler.go:21 +0x50\nnet/http.HandlerFunc.ServeHTTP(0xc000204f80, 0x1e3df60, 0xc0018a8760, 0xc000f28800)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1(0x1e3df60, 0xc0018a8760, 0xc000f28800)\n\t/Users/phil/work/zq/zqd/middleware.go:86 +0x82\nnet/http.HandlerFunc.ServeHTTP(0xc0018a85e0, 0x1e3df60, 0xc0018a8760, 0xc000f28800)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1(0x1e3f620, 0xc0018b60e0, 0xc000f28800)\n\t/Users/phil/work/zq/zqd/middleware.go:66 +0x925\nnet/http.HandlerFunc.ServeHTTP(0xc0018a8600, 0x1e3f620, 0xc0018b60e0, 0xc000f28800)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1(0x1e3f620, 0xc0018b60e0, 0xc000f28600)\n\t/Users/phil/work/zq/zqd/middleware.go:37 +0x2a1\nnet/http.HandlerFunc.ServeHTTP(0xc0018a8620, 0x1e3f620, 0xc0018b60e0, 0xc000f28600)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000246180, 0x1e3f620, 0xc0018b60e0, 0xc000f28400)\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210 +0xe2\nnet/http.serverHandler.ServeHTTP(0xc0001ca380, 0x1e3f620, 0xc0018b60e0, 0xc000f28400)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807 +0xa3\nnet/http.(*conn).serve(0xc0000321e0, 0x1e43960, 0xc000c7f940)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895 +0x86c\ncreated by net/http.(*Server).Serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2933 +0x35c\n\n","request_id":"21","stack":"github.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1\n\t/Users/phil/work/zq/zqd/middleware.go:82\nruntime.gopanic\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967\nruntime.goPanicSliceB\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:116\ngithub.com/brimsec/zq/zcode.(*Iter).Next\n\t/Users/phil/work/zq/zcode/iter.go:31\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:100\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords\n\t/Users/phil/work/zq/zqd/search/json.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch\n\t/Users/phil/work/zq/zqd/search/json.go:49\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write\n\t/Users/phil/work/zq/zqd/search/search.go:144\ngithub.com/brimsec/zq/driver.runMux\n\t/Users/phil/work/zq/driver/driver.go:59\ngithub.com/brimsec/zq/driver.Run\n\t/Users/phil/work/zq/driver/driver.go:30\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run\n\t/Users/phil/work/zq/zqd/search/search.go:84\ngithub.com/brimsec/zq/zqd.handleSearch\n\t/Users/phil/work/zq/zqd/handlers.go:109\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1\n\t/Users/phil/work/zq/zqd/handler.go:21\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:86\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:66\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:37\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807\nnet/http.(*conn).serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895"}
{"level":"dpanic","ts":1598311086.2122948,"msg":"Panic","error":"panic: runtime error: slice bounds out of range [123:26]\ngoroutine 25 [running]:\nruntime/debug.Stack(0xc000185580, 0xc000cf6000, 0x25)\n\t/usr/local/opt/go/libexec/src/runtime/debug/stack.go:24 +0x9d\ngithub.com/brimsec/zq/zqe.RecoverError(0x1b30fa0, 0xc0009760e0, 0xc0009760e0, 0x2af7f60)\n\t/Users/phil/work/zq/zqe/error.go:124 +0x26\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1(0xc000200540, 0xc000534300)\n\t/Users/phil/work/zq/zqd/middleware.go:80 +0x64\npanic(0x1b30fa0, 0xc0009760e0)\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967 +0x15d\ngithub.com/brimsec/zq/zcode.(*Iter).Next(0xc0008f0e18, 0x2af7e40, 0xc000ab206f, 0x3, 0x3f4d, 0x1a0ba60, 0xc003d04490)\n\t/Users/phil/work/zq/zcode/iter.go:31 +0x22c\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer(0x1e47c60, 0xc0004baa20, 0xc000ab2003, 0x89, 0x3fb9, 0x1810, 0xc003d10000, 0xc0008f0fe0, 0x1)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:100 +0x174\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform(0xc0005f8130, 0xc0005ce580, 0x4d, 0xc003d10000, 0x1e47760)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32 +0xf3\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords(0xc0018a82c0, 0xc0008fe800, 0x4d, 0x80, 0x0, 0x0, 0x0, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:32 +0x88\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch(0xc0018a82c0, 0x0, 0x1e47760, 0xc0018a8880, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:49 +0xe1\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write(0xc0018a82e0, 0x0, 0x1e47760, 0xc0018a8880, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:144 +0x51\ngithub.com/brimsec/zq/driver.runMux(0xc00007e2d0, 0x1e43d20, 0xc0018a82e0, 0xc001cda180, 0xc000194070, 0xac442f0)\n\t/Users/phil/work/zq/driver/driver.go:59 +0x253\ngithub.com/brimsec/zq/driver.Run(0x1e43960, 0xc0005ce140, 0x1e43d20, 0xc0018a82e0, 0x1e2c440, 0xc0004ba060, 0xc000194070, 0xac442f0, 0xc00038aa50, 0x0, ...)\n\t/Users/phil/work/zq/driver/driver.go:30 +0x17f\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run(0xc000010020, 0x1e43960, 0xc0005ce140, 0xac44188, 0xc0000f8500, 0x1e43ca0, 0xc0018a82c0, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:84 +0x384\ngithub.com/brimsec/zq/zqd.handleSearch(0xc000202510, 0x1e3df60, 0xc0018a81c0, 0xc000534300)\n\t/Users/phil/work/zq/zqd/handlers.go:109 +0x3f9\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1(0x1e3df60, 0xc0018a81c0, 0xc000534300)\n\t/Users/phil/work/zq/zqd/handler.go:21 +0x50\nnet/http.HandlerFunc.ServeHTTP(0xc000204f80, 0x1e3df60, 0xc0018a81c0, 0xc000534300)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1(0x1e3df60, 0xc0018a81c0, 0xc000534300)\n\t/Users/phil/work/zq/zqd/middleware.go:86 +0x82\nnet/http.HandlerFunc.ServeHTTP(0xc0018a8020, 0x1e3df60, 0xc0018a81c0, 0xc000534300)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1(0x1e3f620, 0xc000630000, 0xc000534300)\n\t/Users/phil/work/zq/zqd/middleware.go:66 +0x925\nnet/http.HandlerFunc.ServeHTTP(0xc0018a8040, 0x1e3f620, 0xc000630000, 0xc000534300)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1(0x1e3f620, 0xc000630000, 0xc000534200)\n\t/Users/phil/work/zq/zqd/middleware.go:37 +0x2a1\nnet/http.HandlerFunc.ServeHTTP(0xc0018a8060, 0x1e3f620, 0xc000630000, 0xc000534200)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000246180, 0x1e3f620, 0xc000630000, 0xc000534000)\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210 +0xe2\nnet/http.serverHandler.ServeHTTP(0xc0001ca380, 0x1e3f620, 0xc000630000, 0xc000534000)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807 +0xa3\nnet/http.(*conn).serve(0xc0000321e0, 0x1e43960, 0xc000c7f940)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895 +0x86c\ncreated by net/http.(*Server).Serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2933 +0x35c\n\n","request_id":"27","stack":"github.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1\n\t/Users/phil/work/zq/zqd/middleware.go:82\nruntime.gopanic\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967\nruntime.goPanicSliceB\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:116\ngithub.com/brimsec/zq/zcode.(*Iter).Next\n\t/Users/phil/work/zq/zcode/iter.go:31\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:100\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords\n\t/Users/phil/work/zq/zqd/search/json.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch\n\t/Users/phil/work/zq/zqd/search/json.go:49\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write\n\t/Users/phil/work/zq/zqd/search/search.go:144\ngithub.com/brimsec/zq/driver.runMux\n\t/Users/phil/work/zq/driver/driver.go:59\ngithub.com/brimsec/zq/driver.Run\n\t/Users/phil/work/zq/driver/driver.go:30\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run\n\t/Users/phil/work/zq/zqd/search/search.go:84\ngithub.com/brimsec/zq/zqd.handleSearch\n\t/Users/phil/work/zq/zqd/handlers.go:109\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1\n\t/Users/phil/work/zq/zqd/handler.go:21\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:86\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:66\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:37\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807\nnet/http.(*conn).serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895"}
{"level":"dpanic","ts":1598311103.534545,"msg":"Panic","error":"panic: runtime error: index out of range [0] with length 0\ngoroutine 25 [running]:\nruntime/debug.Stack(0xc000185580, 0xc000cf6000, 0x25)\n\t/usr/local/opt/go/libexec/src/runtime/debug/stack.go:24 +0x9d\ngithub.com/brimsec/zq/zqe.RecoverError(0x1b30fa0, 0xc005962080, 0xc005962080, 0x2af7f60)\n\t/Users/phil/work/zq/zqe/error.go:124 +0x26\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1(0xc000200540, 0xc008620300)\n\t/Users/phil/work/zq/zqd/middleware.go:80 +0x64\npanic(0x1b30fa0, 0xc005962080)\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967 +0x15d\ngithub.com/brimsec/zq/zng.DecodeBool(...)\n\t/Users/phil/work/zq/zng/bool.go:26\ngithub.com/brimsec/zq/zng.(*TypeOfBool).StringOf(0x2af7e40, 0xc00867204b, 0x0, 0x3f81, 0x0, 0x0, 0x3f82, 0x2)\n\t/Users/phil/work/zq/zng/bool.go:49 +0x1dd\ngithub.com/brimsec/zq/zng.Value.Format(...)\n\t/Users/phil/work/zq/zng/value.go:77\ngithub.com/brimsec/zq/zio/zjsonio.encodePrimitive(0x1e47820, 0x2af7e40, 0xc00867204b, 0x0, 0x3f81, 0x0, 0x0, 0x0, 0x0)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:80 +0xf7\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer(0x1e47c60, 0xc00861ca80, 0xc008672002, 0x73, 0x3fca, 0x1f40, 0xc00594c000, 0xc008642fb8, 0x1)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:134 +0x5ac\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform(0xc0086141b0, 0xc008618540, 0x64, 0xc00594c000, 0x1e47760)\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32 +0xf3\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords(0xc008616380, 0xc00867a000, 0x64, 0x100, 0x0, 0x0, 0x0, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:32 +0x88\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch(0xc008616380, 0x0, 0x1e47760, 0xc008616840, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/json.go:49 +0xe1\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write(0xc0086163a0, 0x0, 0x1e47760, 0xc008616840, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:144 +0x51\ngithub.com/brimsec/zq/driver.runMux(0xc000a082d0, 0x1e43d20, 0xc0086163a0, 0xc0086101e0, 0xc0001942a0, 0xac442f0)\n\t/Users/phil/work/zq/driver/driver.go:59 +0x253\ngithub.com/brimsec/zq/driver.Run(0x1e43960, 0xc0086181c0, 0x1e43d20, 0xc0086163a0, 0x1e2c440, 0xc00861c480, 0xc0001942a0, 0xac442f0, 0xc00038abb0, 0x0, ...)\n\t/Users/phil/work/zq/driver/driver.go:30 +0x17f\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run(0xc000010048, 0x1e43960, 0xc0086181c0, 0xac44188, 0xc0000f8500, 0x1e43ca0, 0xc008616380, 0x0, 0x0)\n\t/Users/phil/work/zq/zqd/search/search.go:84 +0x384\ngithub.com/brimsec/zq/zqd.handleSearch(0xc000202510, 0x1e3df60, 0xc008616280, 0xc008620300)\n\t/Users/phil/work/zq/zqd/handlers.go:109 +0x3f9\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1(0x1e3df60, 0xc008616280, 0xc008620300)\n\t/Users/phil/work/zq/zqd/handler.go:21 +0x50\nnet/http.HandlerFunc.ServeHTTP(0xc000204f80, 0x1e3df60, 0xc008616280, 0xc008620300)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1(0x1e3df60, 0xc008616280, 0xc008620300)\n\t/Users/phil/work/zq/zqd/middleware.go:86 +0x82\nnet/http.HandlerFunc.ServeHTTP(0xc0086160e0, 0x1e3df60, 0xc008616280, 0xc008620300)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1(0x1e3f620, 0xc00862e000, 0xc008620300)\n\t/Users/phil/work/zq/zqd/middleware.go:66 +0x925\nnet/http.HandlerFunc.ServeHTTP(0xc008616100, 0x1e3f620, 0xc00862e000, 0xc008620300)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1(0x1e3f620, 0xc00862e000, 0xc008620200)\n\t/Users/phil/work/zq/zqd/middleware.go:37 +0x2a1\nnet/http.HandlerFunc.ServeHTTP(0xc008616120, 0x1e3f620, 0xc00862e000, 0xc008620200)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000246180, 0x1e3f620, 0xc00862e000, 0xc008620000)\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210 +0xe2\nnet/http.serverHandler.ServeHTTP(0xc0001ca380, 0x1e3f620, 0xc00862e000, 0xc008620000)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807 +0xa3\nnet/http.(*conn).serve(0xc0000321e0, 0x1e43960, 0xc000c7f940)\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895 +0x86c\ncreated by net/http.(*Server).Serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2933 +0x35c\n\n","request_id":"39","stack":"github.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1.1\n\t/Users/phil/work/zq/zqd/middleware.go:82\nruntime.gopanic\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:967\nruntime.goPanicIndex\n\t/usr/local/opt/go/libexec/src/runtime/panic.go:88\ngithub.com/brimsec/zq/zng.DecodeBool\n\t/Users/phil/work/zq/zng/bool.go:26\ngithub.com/brimsec/zq/zng.(*TypeOfBool).StringOf\n\t/Users/phil/work/zq/zng/bool.go:49\ngithub.com/brimsec/zq/zng.Value.Format\n\t/Users/phil/work/zq/zng/value.go:77\ngithub.com/brimsec/zq/zio/zjsonio.encodePrimitive\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:80\ngithub.com/brimsec/zq/zio/zjsonio.encodeContainer\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:134\ngithub.com/brimsec/zq/zio/zjsonio.(*Stream).Transform\n\t/Users/phil/work/zq/zio/zjsonio/stream.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).formatRecords\n\t/Users/phil/work/zq/zqd/search/json.go:32\ngithub.com/brimsec/zq/zqd/search.(*JSON).SendBatch\n\t/Users/phil/work/zq/zqd/search/json.go:49\ngithub.com/brimsec/zq/zqd/search.(*searchdriver).Write\n\t/Users/phil/work/zq/zqd/search/search.go:144\ngithub.com/brimsec/zq/driver.runMux\n\t/Users/phil/work/zq/driver/driver.go:59\ngithub.com/brimsec/zq/driver.Run\n\t/Users/phil/work/zq/driver/driver.go:30\ngithub.com/brimsec/zq/zqd/search.(*SearchOp).Run\n\t/Users/phil/work/zq/zqd/search/search.go:84\ngithub.com/brimsec/zq/zqd.handleSearch\n\t/Users/phil/work/zq/zqd/handlers.go:109\ngithub.com/brimsec/zq/zqd.(*handler).Handle.func1\n\t/Users/phil/work/zq/zqd/handler.go:21\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.panicCatchMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:86\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.accessLogMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:66\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/brimsec/zq/zqd.requestIDMiddleware.func1.1\n\t/Users/phil/work/zq/zqd/middleware.go:37\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2012\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/mux@v1.7.5-0.20200711200521-98cb6bf42e08/mux.go:210\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2807\nnet/http.(*conn).serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1895"}

Thanks @mattnibs!