"Malformed zng record" error when importing pcapng

[philrz]

Repro is with Brim commit 6078840 talking to zed commit aa4170e and using Brimcap commit 3323b0e.

As shown in the attached video, when I open causes-malformed-zng.pcapng.gz (after uncompressing) in Brim, a "Malformed zng record" pops up at the end.

Repro.mp4

Here's the contents of the zlake.log from behind the app:

{"level":"info","ts":1619811822.5072582,"msg":"Open files limit raised","limit":24576}
{"level":"info","ts":1619811822.507597,"msg":"Listening to brim process pipe","fd":"brimfd"}
{"level":"info","ts":1619811822.509144,"logger":"core","msg":"Started"}
{"level":"info","ts":1619811822.5117319,"logger":"httpd","msg":"Listening","addr":"127.0.0.1:9867"}
{"level":"info","ts":1619811825.389148,"logger":"http.access","msg":"Request completed","request_id":"1ru2o2qzsDAvR2oGbIPVaNMo115","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool","elapsed":0.000098819,"response_content_length":5,"status_code":200}
{"level":"info","ts":1619811852.2473311,"logger":"http.access","msg":"Request completed","request_id":"1ru2rYCPuVdF3RSYgolZuGKAtpl","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":38,"url":"/pool","elapsed":0.001700236,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811852.268482,"logger":"http.access","msg":"Request completed","request_id":"1ru2rX9eJcYedZqQgaGxFHPrY85","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000187244,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811852.335582,"logger":"http.access","msg":"Request completed","request_id":"1ru2rT9HeyCjJVY0fFtytUoXLZC","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63933","request_content_length":0,"url":"/pool","elapsed":0.000012948,"response_content_length":76,"status_code":200}
{"level":"warn","ts":1619811852.6749399,"logger":"core","msg":"Error writing response","request_id":"1ru2rWzXiQIxzkBrr2zZwLL90JS","error":"empty log","stacktrace":"github.com/brimdata/zed/service.handleSearch\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/handlers.go:117\ngithub.com/brimdata/zed/service.(*Core).handler.func1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/core.go:137\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.panicCatchMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:75\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.accessLogMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:55\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.requestIDMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:27\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/[email protected]/mux.go:210\ngithub.com/brimdata/zed/service.(*Core).ServeHTTP\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/core.go:161\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2887\nnet/http.(*conn).serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1952"}
{"level":"info","ts":1619811852.675093,"logger":"http.access","msg":"Request completed","request_id":"1ru2rWzXiQIxzkBrr2zZwLL90JS","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63935","request_content_length":248,"url":"/search?format=zjson","elapsed":0.00158446,"response_content_length":66,"status_code":200}
{"level":"warn","ts":1619811852.677512,"logger":"core","msg":"Error writing response","request_id":"1ru2rXXykYCHWpnLGmuy7fUDRz1","error":"empty log","stacktrace":"github.com/brimdata/zed/service.handleSearch\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/handlers.go:117\ngithub.com/brimdata/zed/service.(*Core).handler.func1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/core.go:137\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.panicCatchMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:75\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.accessLogMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:55\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.requestIDMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:27\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/[email protected]/mux.go:210\ngithub.com/brimdata/zed/service.(*Core).ServeHTTP\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/core.go:161\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2887\nnet/http.(*conn).serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1952"}
{"level":"info","ts":1619811852.677623,"logger":"http.access","msg":"Request completed","request_id":"1ru2rXXykYCHWpnLGmuy7fUDRz1","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":493,"url":"/search?format=zjson","elapsed":0.004282261,"response_content_length":66,"status_code":200}
{"level":"info","ts":1619811853.3783832,"logger":"http.access","msg":"Request completed","request_id":"1ru2rfI8NdRY7DC5jnfGrdyDQkP","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000146797,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811854.392313,"logger":"http.access","msg":"Request completed","request_id":"1ru2rjaIOXqAbtEd8efdvOjVCuF","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000205759,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811855.38918,"logger":"http.access","msg":"Request completed","request_id":"1ru2rsFKsXGUsqYgRLABlgfwIXs","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000174674,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811856.38336,"logger":"http.access","msg":"Request completed","request_id":"1ru2ryh5YJLVYwj1Duedj3qfWJY","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000252641,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811857.383342,"logger":"http.access","msg":"Request completed","request_id":"1ru2s8usoJWRCm8KaKLKAjIPMRJ","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000238062,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811858.367014,"logger":"http.access","msg":"Request completed","request_id":"1ru2sI8jMCDT9zJOfZsSNSlCvxJ","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000137669,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811859.363219,"logger":"http.access","msg":"Request completed","request_id":"1ru2sKwuoBeJXwFxpWLLy1TA3EL","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000180119,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811860.3739479,"logger":"http.access","msg":"Request completed","request_id":"1ru2sRmBnn0KXfCyG4AEXhBwOAh","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000142593,"response_content_length":74,"status_code":200}
{"level":"info","ts":1619811860.409612,"logger":"http.access","msg":"Request completed","request_id":"1ru2rRzlPpw8Rg6z6332xZFwL7s","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63933","request_content_length":-1,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB/log","elapsed":8.073331366,"response_content_length":100,"status_code":200}
{"level":"info","ts":1619811860.4455712,"logger":"http.access","msg":"Request completed","request_id":"1ru2sTJTChvSKupWWNZveKyhGPF","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.000890229,"response_content_length":164,"status_code":200}
{"level":"info","ts":1619811860.449198,"logger":"http.access","msg":"Request completed","request_id":"1ru2sR9ie62YMEuguxNmI31tL0V","host":"localhost:9867","method":"GET","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":0,"url":"/pool/1ru2rU4jmVfTEFGRAHoSnPU4VMB","elapsed":0.001088578,"response_content_length":164,"status_code":200}
{"level":"info","ts":1619811860.5706408,"logger":"http.access","msg":"Request completed","request_id":"1ru2sVMvKCRxGSfVgkz4PfziR5f","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63935","request_content_length":267,"url":"/search?format=zjson","elapsed":0.005341908,"response_content_length":8859,"status_code":200}
{"level":"info","ts":1619811860.5736299,"logger":"http.access","msg":"Request completed","request_id":"1ru2sS7U8ibDHBnQbx0If1Uhk4i","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":512,"url":"/search?format=zjson","elapsed":0.008392522,"response_content_length":730,"status_code":200}
{"level":"info","ts":1619811860.750759,"logger":"http.access","msg":"Request completed","request_id":"1ru2sRiJ7b6wLOG3tPZ7V1lBEts","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63935","request_content_length":267,"url":"/search?format=zjson","elapsed":0.004327341,"response_content_length":8859,"status_code":200}
{"level":"info","ts":1619811860.753555,"logger":"http.access","msg":"Request completed","request_id":"1ru2sW4WL6wEEOX0rgFCb0iOujc","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":512,"url":"/search?format=zjson","elapsed":0.007386692,"response_content_length":730,"status_code":200}
{"level":"warn","ts":1619811861.409067,"logger":"core","msg":"Error writing response","request_id":"1ru2sfH3qVFKOIQCPK1lIQucyGw","error":"malformed zng record","stacktrace":"github.com/brimdata/zed/service.handleSearch\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/handlers.go:117\ngithub.com/brimdata/zed/service.(*Core).handler.func1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/core.go:137\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.panicCatchMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:75\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.accessLogMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:55\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/brimdata/zed/service.requestIDMiddleware.func1.1\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/middleware.go:27\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2069\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\t/Users/phil/.go/pkg/mod/github.com/gorilla/[email protected]/mux.go:210\ngithub.com/brimdata/zed/service.(*Core).ServeHTTP\n\t/Users/phil/.npm/_cacache/tmp/git-clone-d5ca8e07/service/core.go:161\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/opt/go/libexec/src/net/http/server.go:2887\nnet/http.(*conn).serve\n\t/usr/local/opt/go/libexec/src/net/http/server.go:1952"}
{"level":"info","ts":1619811861.4091468,"logger":"http.access","msg":"Request completed","request_id":"1ru2sfH3qVFKOIQCPK1lIQucyGw","host":"localhost:9867","method":"POST","proto":"HTTP/1.1","remote_addr":"127.0.0.1:63925","request_content_length":267,"url":"/search?format=zjson","elapsed":0.002431492,"response_content_length":137,"status_code":200}

[philrz]

I noticed this one magically went away recently. A binary search revealed this started working at Brim commit 3c72f6a which is associated with the advance of its Zed dependency to commit 035b439, which in turn is associated with the fix in #2745.

Here's the video verification that there's no longer an error pop-up:

Verify.mp4

Thanks @nwt!