Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

"panic: runtime error: index out of range" from spread attempt on error value #4349

Closed
philrz opened this issue Jan 31, 2023 · 1 comment · Fixed by #4359
Closed

"panic: runtime error: index out of range" from spread attempt on error value #4349

philrz opened this issue Jan 31, 2023 · 1 comment · Fixed by #4359
Assignees
Labels
bug Something isn't working community

Comments

@philrz
Copy link
Contributor

philrz commented Jan 31, 2023

Repro is with Zui commit b9561cf which uses Zed da55f70. The repro in Zui is shown for effect, but the problem is ultimately at the Zed layer.

I think the community zync user originally triggered this issue because their data had a field value that typically stored a record but sometimes it contained an error. Therefore a super simple way I've found to trigger the problem is with just the input data:

$ cat value-error.zson 
{value:error("missing")}

As shown in the attached video, if this is imported into the app and the query yield {...value} is executed, a panic dump appears in the Zed lake log. The zed serve process does not exit.

Repro.mp4

Reproducing this with zq outside the app, the dump is easier to see.

$ zq -version
Version: v1.4.0-34-gda55f701

$ zq -f zjson 'yield {...value}' value-error.zson 
panic: runtime error: index out of range [0] with length 0

goroutine 1 [running]:
github.com/brimdata/zed/zio/zjsonio.(*Writer).encodeRecord(0x1e?, 0x20913c0?, 0xc000191650, {0xc000049ab0?, 0xc000190510?, 0x2097628?})
	/Users/phil/work/zed/zio/zjsonio/writer.go:152 +0x207
github.com/brimdata/zed/zio/zjsonio.(*Writer).encodeValue(0x1cc9f80?, 0x2097628?, {0x2097628?, 0xc000191650?}, {0xc000049ab0?, 0x8?, 0xc00021fa80?})
	/Users/phil/work/zed/zio/zjsonio/writer.go:113 +0x7a
github.com/brimdata/zed/zio/zjsonio.(*Writer).Transform(0xc000190540, 0xc0001914d0)
	/Users/phil/work/zed/zio/zjsonio/writer.go:100 +0x11a
github.com/brimdata/zed/zio/zjsonio.(*Writer).Write(0xc000190540, 0xc00021fb00?)
	/Users/phil/work/zed/zio/zjsonio/writer.go:67 +0x2e
github.com/brimdata/zed/zbuf.WriteBatch({0x2b78c618, 0xc000190540}, {0x209fbd8?, 0xc0001915f0?})
	/Users/phil/work/zed/zbuf/batch.go:37 +0x77
github.com/brimdata/zed/zbuf.CopyPuller({0x2b78c618, 0xc000190540}, {0x208fdc0, 0xc0001911d0})
	/Users/phil/work/zed/zbuf/batch.go:110 +0x7c
github.com/brimdata/zed/cli/zq.(*Command).Run(0xc0000dc540, {0xc000132030, 0x2, 0x2})
	/Users/phil/work/zed/cli/zq/command.go:162 +0x778
github.com/brimdata/zed/pkg/charm.path.run({0xc0000140e0?, 0x1, 0x1}, {0xc000132030?, 0x2, 0x0?})
	/Users/phil/work/zed/pkg/charm/path.go:11 +0x8b
github.com/brimdata/zed/pkg/charm.(*Spec).ExecRoot(0xc0000061a0?, {0xc000132010, 0x4, 0x4})
	/Users/phil/work/zed/pkg/charm/charm.go:63 +0x4a
main.main()
	/Users/phil/work/zed/cmd/zq/main.go:11 +0x5d

While the user's error values seemed like an important ingredient in their originally hitting the bug, I've also found that I can trigger a similar dump with other data such as an empty record and other formats such as CSV.

$ echo '{}' | zq -f csv 'yield {...value}' -
panic: runtime error: index out of range [0] with length 0

goroutine 1 [running]:
github.com/brimdata/zed/runtime/expr.recode({0x0?, 0xc0004f6d80?, 0x2097628?}, 0xc0004f6d80, {0xc0005a5eb0?, 0x203000?, 0x0?})
	/Users/phil/work/zed/runtime/expr/flattener.go:48 +0x575
github.com/brimdata/zed/runtime/expr.(*Flattener).Flatten(0xc000590eb0, 0xc0004f6de0)
	/Users/phil/work/zed/runtime/expr/flattener.go:77 +0x176
github.com/brimdata/zed/zio/csvio.(*Writer).Write(0xc000522c80, 0xc0004f6de0)
	/Users/phil/work/zed/zio/csvio/writer.go:52 +0x6c
github.com/brimdata/zed/zbuf.WriteBatch({0x2b729a18, 0xc000522c80}, {0x209fbd8?, 0xc0004f6ea0?})
	/Users/phil/work/zed/zbuf/batch.go:37 +0x77
github.com/brimdata/zed/zbuf.CopyPuller({0x2b729a18, 0xc000522c80}, {0x208fdc0, 0xc0004f6d20})
	/Users/phil/work/zed/zbuf/batch.go:110 +0x7c
github.com/brimdata/zed/cli/zq.(*Command).Run(0xc00072e1c0, {0xc0000400d0, 0x2, 0x2})
	/Users/phil/work/zed/cli/zq/command.go:162 +0x778
github.com/brimdata/zed/pkg/charm.path.run({0xc00074c010?, 0x1, 0x1}, {0xc0000400d0?, 0x2, 0x0?})
	/Users/phil/work/zed/pkg/charm/path.go:11 +0x8b
github.com/brimdata/zed/pkg/charm.(*Spec).ExecRoot(0xc0000061a0?, {0xc0000400b0, 0x4, 0x4})
	/Users/phil/work/zed/pkg/charm/charm.go:63 +0x4a
main.main()
	/Users/phil/work/zed/cmd/zq/main.go:11 +0x5d

It also looks like this issue has maybe always been there. He's a repro back at GA Zed tagged v1.1.0.

$ zq -version
Version: v1.1.0

$ echo '{}' | zq -f zjson 'yield {...value}' -
panic: runtime error: index out of range [0] with length 0
...

In addition the specific crash, I'm also a little troubled by the silence in the app. I used Wireshark to sniff the API traffic and as shown below, the dump we saw in the lake log file doesn't show up in the API response, so it makes sense that we saw nothing in the app.

image

I'm having difficulty keeping track of what we should expect here regarding such errors. When I last visited the topic in the context of brimdata/zui#2620, unlike what we saw above, the panic then was presented in the app.

In any case, it seems it would be ideal if errors showed up in the log file and the app whenever possible since silence in response to a query is typically interpreted by the user as "no results found" rather than "something crashed". We could open up a separate issue if this topic needs to be handled separately.

@philrz philrz added bug Something isn't working community labels Jan 31, 2023
@nwt nwt self-assigned this Jan 31, 2023
nwt added a commit that referenced this issue Feb 2, 2023
A record spread expression that produces an empty record (e.g., "{...a}"
evaluated with "this" bound to a Zed primitive value) results in a
zed.Value with malformed bytes, which can cause a panic elsewhere.  Fix
this in recordSpreadExpr.Eval by returning a well-formed zed.Value.

For better or worse, we don't have any existing tests for malfored
zed.Values, so I'm not adding one here.

Closes #4349.
nwt added a commit that referenced this issue Feb 2, 2023
A record spread expression that produces an empty record (e.g., "{...a}"
evaluated with "this" bound to a Zed primitive value) results in a
zed.Value with malformed bytes, which can cause a panic elsewhere.  Fix
this in recordSpreadExpr.Eval by returning a well-formed zed.Value.

For better or worse, we don't have any existing tests for malformed
zed.Values, so I'm not adding one here.

Closes #4349.
@nwt nwt closed this as completed in #4359 Feb 2, 2023
nwt added a commit that referenced this issue Feb 2, 2023
A record spread expression that produces an empty record (e.g., "{...a}"
evaluated with "this" bound to a Zed primitive value) results in a
zed.Value with malformed bytes, which can cause a panic elsewhere.  Fix
this in recordSpreadExpr.Eval by returning a well-formed zed.Value.

For better or worse, we don't have any existing tests for malformed
zed.Values, so I'm not adding one here.

Closes #4349.
@philrz
Copy link
Contributor Author

philrz commented Feb 3, 2023

Verified in Zui commit 1e0a608 which uses Zed commit 82ddbf2.

As shown in the attached video, the spread attempt no longer causes a panic and stack dump in the Zed lake log.

Verify.mp4

Also here's proof of success with the CLI tooling:

$ zq -version
Version: v1.5.0-15-g743eebda

$ zq -f zjson 'yield {...value}' value-error.zson 
{"type":{"kind":"record","id":30,"fields":null},"value":[]}

Alas, the video shows the app still struggling to correctly present the value, so I've added a comment to an existing issue at brimdata/zui#2454 (comment) where a similar problem is already being tracked.

Also, I'm still concerned about the fact the panic was not making its way back in the API response to be surfaced to the user, so I've opened a new issue #4363 to track that in general.

Thanks @nwt!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working community
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants