release-24.1: colexecerror: avoid debug.Stack in CatchVectorizedRuntimeError #123499
Conversation
![blathers-crl[bot]](https://avatars.githubusercontent.com/in/59700?s=60&v=4){kind=small}
Informs: #123235 Release note: None
Informs: #123235 Release note: None
Informs: #123235 Release note: None
Fixes: #123235 Release note (performance improvement): Make error handling in the vectorized execution engine much cheaper. This should help avoid bad metastable regimes perpetuated by statement timeout handling consuming all CPU time, leading to more statement timeouts.
blathers-crl
bot
force-pushed
the
blathers/backport-release-24.1-123277
branch
from
fbde5c2
to
fab0529
Compare
blathers-crl
bot
added
blathers-backport
![blathers[crl]](https://avatars.githubusercontent.com/in/59700?s=40&u=373d9101a12edc3847d2fb6ae78e3adcfb4ca41e&v=4){kind=avatar}
|
Thanks for opening a backport. Please check the backport criteria before merging:
If your backport adds new functionality, please ensure that the following additional criteria are satisfied:
Also, please add a brief release justification to the body of your PR to justify this |
blathers-crl
bot
requested review from
mgartner,
michae2,
petermattis,
rafiss and
yuzefovich
blathers-crl
bot
added
the
backport
|
This change is |
There was a problem hiding this comment.
Reviewed 7 of 7 files at r1, 1 of 1 files at r2, 1 of 1 files at r3, 1 of 1 files at r4, all commit messages.
Reviewable status:complete! 1 of 0 LGTMs obtained (waiting on @mgartner, @michae2, and @rafiss)
There was a problem hiding this comment.
Reviewed 6 of 7 files at r1, 1 of 1 files at r4, all commit messages.
Reviewable status:
There was a problem hiding this comment.
Reviewed 7 of 7 files at r1, 1 of 1 files at r2, 1 of 1 files at r3, 1 of 1 files at r4, all commit messages.
Reviewable status:
pkg/sql/colexecerror/error.go line 87 at r4 (raw file):
var panicEmittedFrom string // We should be able to find it within 3 program counters, starting with the // caller of this deferred function (2 above the runtime.Callers frame).
IIRC this was discussed in Slack, but can't find the thread. What is the reasoning for only checking 3 pcs (or 5) PCs deep?
pkg/sql/colexecerror/error.go line 88 at r4 (raw file):
// We should be able to find it within 3 program counters, starting with the // caller of this deferred function (2 above the runtime.Callers frame). pc := make([]uintptr, 3)
nit: this could be an array [3]uintptr to avoid an allocation.
There was a problem hiding this comment.
Reviewable status:
pkg/sql/colexecerror/error.go line 87 at r4 (raw file):
Previously, mgartner (Marcus Gartner) wrote…
IIRC this was discussed in Slack, but can't find the thread. What is the reasoning for only checking 3 pcs (or 5) PCs deep?
We expect the stack to look something like this when we catch the panic:
github.com/cockroachdb/cockroach/pkg/sql/colexecerror.CatchVectorizedRuntimeError.func1()
github.com/cockroachdb/cockroach/pkg/sql/colexecerror/error.go:90 +0x110
panic({0x1069ad940?, 0x10ab3a8c0?})
GOROOT/src/runtime/panic.go:770 +0x124
github.com/cockroachdb/cockroach/pkg/sql/sem/builtins.init.func625({0x107466690?, 0x140058f4db0?}, 0x140058f4db0?, {0x140060d43a0, 0x2, 0x107466690?})
github.com/cockroachdb/cockroach/pkg/sql/sem/builtins/builtins.go:5724 +0x410
github.com/cockroachdb/cockroach/pkg/sql/sem/eval.(*evaluator).EvalFuncExpr(0x14003970008, {0x107466690, 0x140058f4db0}, 0x14003a22480)
github.com/cockroachdb/cockroach/pkg/sql/sem/eval/expr.go:483 +0xe4
github.com/cockroachdb/cockroach/pkg/sql/sem/tree.(*FuncExpr).Eval(0x14005861900?, {0x107466690?, 0x140058f4db0?}, {0x107503080?, 0x14003970008?})
github.com/cockroachdb/cockroach/bazel-out/darwin_arm64-fastbuild/bin/pkg/sql/sem/tree/eval_expr_generated.go:282 +0x38
github.com/cockroachdb/cockroach/pkg/sql/sem/eval.Expr(...)
github.com/cockroachdb/cockroach/pkg/sql/sem/eval/expr.go:26
github.com/cockroachdb/cockroach/pkg/sql.(*valuesNode).startExec(0x14003281080, {{0x107466690, 0x140058f4db0}, 0x14003970008, 0x140043e9988})
github.com/cockroachdb/cockroach/pkg/sql/values.go:89 +0x228
github.com/cockroachdb/cockroach/pkg/sql.startExec.func2({0x11414bae0?, 0x140058f4de0?}, {0x107469250, 0x14003281080})
github.com/cockroachdb/cockroach/pkg/sql/plan.go:520 +0xfc
github.com/cockroachdb/cockroach/pkg/sql.(*planVisitor).visitInternal.func1()
github.com/cockroachdb/cockroach/pkg/sql/walk.go:112 +0x44
github.com/cockroachdb/cockroach/pkg/sql.(*planVisitor).visitInternal(0x14003c52b58, {0x107469250?, 0x14003281080}, {0x104c473d9?, 0x6?})
github.com/cockroachdb/cockroach/pkg/sql/walk.go:299 +0x1594
github.com/cockroachdb/cockroach/pkg/sql.(*planVisitor).visit(0x14003c52b58, {0x107469250, 0x14003281080})
github.com/cockroachdb/cockroach/pkg/sql/walk.go:79 +0xe8
github.com/cockroachdb/cockroach/pkg/sql.walkPlan(...)
github.com/cockroachdb/cockroach/pkg/sql/walk.go:43
github.com/cockroachdb/cockroach/pkg/sql.startExec({{0x107466690?, 0x140058f4db0?}, 0x14003970008?, 0x140043e9988?}, {0x107469250, 0x14003281080})
github.com/cockroachdb/cockroach/pkg/sql/plan.go:523 +0xdc
github.com/cockroachdb/cockroach/pkg/sql.(*planNodeToRowSource).Start(0x140077d1c08, {0x107466690, 0x140058f4d80})
github.com/cockroachdb/cockroach/pkg/sql/plan_node_to_row_source.go:175 +0xf0
github.com/cockroachdb/cockroach/pkg/sql/colexec.(*Columnarizer).Init(0x14003927808, {0x107466690, 0x140058f4d50})
github.com/cockroachdb/cockroach/pkg/sql/colexec/columnarizer.go:183 +0xd0
github.com/cockroachdb/cockroach/pkg/sql/colflow.(*batchInfoCollector).init(...)
github.com/cockroachdb/cockroach/pkg/sql/colflow/stats.go:94
...
The panic() should always be the frame before the deferred function doing the recover, and we want to look at the frame before the panic frame.
So:
runtime.Callers(0, [1]uintptr)would be the call toruntime.Callersruntime.Callers(1, [1]uintptr)would be the call tocolexecerror.CatchVectorizedRuntimeError.func1runtime.Callers(2, [1]uintptr)would be the call topanicruntime.Callers(2, [2]uintptr)would be the call topanic+ frame beforeruntime.Callers(2, [3]uintptr)would be the call topanic+ two frames before, just for safety
pkg/sql/colexecerror/error.go line 88 at r4 (raw file):
Previously, mgartner (Marcus Gartner) wrote…
nit: this could be an array
[3]uintptrto avoid an allocation.
Ah, drat, good point.
There was a problem hiding this comment.
Reviewable status:
pkg/sql/colexecerror/error.go line 87 at r4 (raw file):
Previously, michae2 (Michael Erickson) wrote…
We expect the stack to look something like this when we catch the panic:
github.com/cockroachdb/cockroach/pkg/sql/colexecerror.CatchVectorizedRuntimeError.func1() github.com/cockroachdb/cockroach/pkg/sql/colexecerror/error.go:90 +0x110 panic({0x1069ad940?, 0x10ab3a8c0?}) GOROOT/src/runtime/panic.go:770 +0x124 github.com/cockroachdb/cockroach/pkg/sql/sem/builtins.init.func625({0x107466690?, 0x140058f4db0?}, 0x140058f4db0?, {0x140060d43a0, 0x2, 0x107466690?}) github.com/cockroachdb/cockroach/pkg/sql/sem/builtins/builtins.go:5724 +0x410 github.com/cockroachdb/cockroach/pkg/sql/sem/eval.(*evaluator).EvalFuncExpr(0x14003970008, {0x107466690, 0x140058f4db0}, 0x14003a22480) github.com/cockroachdb/cockroach/pkg/sql/sem/eval/expr.go:483 +0xe4 github.com/cockroachdb/cockroach/pkg/sql/sem/tree.(*FuncExpr).Eval(0x14005861900?, {0x107466690?, 0x140058f4db0?}, {0x107503080?, 0x14003970008?}) github.com/cockroachdb/cockroach/bazel-out/darwin_arm64-fastbuild/bin/pkg/sql/sem/tree/eval_expr_generated.go:282 +0x38 github.com/cockroachdb/cockroach/pkg/sql/sem/eval.Expr(...) github.com/cockroachdb/cockroach/pkg/sql/sem/eval/expr.go:26 github.com/cockroachdb/cockroach/pkg/sql.(*valuesNode).startExec(0x14003281080, {{0x107466690, 0x140058f4db0}, 0x14003970008, 0x140043e9988}) github.com/cockroachdb/cockroach/pkg/sql/values.go:89 +0x228 github.com/cockroachdb/cockroach/pkg/sql.startExec.func2({0x11414bae0?, 0x140058f4de0?}, {0x107469250, 0x14003281080}) github.com/cockroachdb/cockroach/pkg/sql/plan.go:520 +0xfc github.com/cockroachdb/cockroach/pkg/sql.(*planVisitor).visitInternal.func1() github.com/cockroachdb/cockroach/pkg/sql/walk.go:112 +0x44 github.com/cockroachdb/cockroach/pkg/sql.(*planVisitor).visitInternal(0x14003c52b58, {0x107469250?, 0x14003281080}, {0x104c473d9?, 0x6?}) github.com/cockroachdb/cockroach/pkg/sql/walk.go:299 +0x1594 github.com/cockroachdb/cockroach/pkg/sql.(*planVisitor).visit(0x14003c52b58, {0x107469250, 0x14003281080}) github.com/cockroachdb/cockroach/pkg/sql/walk.go:79 +0xe8 github.com/cockroachdb/cockroach/pkg/sql.walkPlan(...) github.com/cockroachdb/cockroach/pkg/sql/walk.go:43 github.com/cockroachdb/cockroach/pkg/sql.startExec({{0x107466690?, 0x140058f4db0?}, 0x14003970008?, 0x140043e9988?}, {0x107469250, 0x14003281080}) github.com/cockroachdb/cockroach/pkg/sql/plan.go:523 +0xdc github.com/cockroachdb/cockroach/pkg/sql.(*planNodeToRowSource).Start(0x140077d1c08, {0x107466690, 0x140058f4d80}) github.com/cockroachdb/cockroach/pkg/sql/plan_node_to_row_source.go:175 +0xf0 github.com/cockroachdb/cockroach/pkg/sql/colexec.(*Columnarizer).Init(0x14003927808, {0x107466690, 0x140058f4d50}) github.com/cockroachdb/cockroach/pkg/sql/colexec/columnarizer.go:183 +0xd0 github.com/cockroachdb/cockroach/pkg/sql/colflow.(*batchInfoCollector).init(...) github.com/cockroachdb/cockroach/pkg/sql/colflow/stats.go:94 ...The
panic()should always be the frame before the deferred function doing therecover, and we want to look at the frame before the panic frame.So:
runtime.Callers(0, [1]uintptr)would be the call toruntime.Callersruntime.Callers(1, [1]uintptr)would be the call tocolexecerror.CatchVectorizedRuntimeError.func1runtime.Callers(2, [1]uintptr)would be the call topanicruntime.Callers(2, [2]uintptr)would be the call topanic+ frame beforeruntime.Callers(2, [3]uintptr)would be the call topanic+ two frames before, just for safety
Thanks for spelling it out for me! This was helpful.
I suppose this is robust because Go does not allow import cycles, so we would never see a stack like:
colexecerror.CatchVectorizedRuntimeError.func1
panic
pkg/sql/colexec
...
pkg/sql/sem/builtins
...
pkg/sql/colexec
Although maybe that is possible in some cases where we avoid cycles by setting global variables in a package. 🤷
pkg/sql/colexecerror/error.go line 88 at r4 (raw file):
Previously, michae2 (Michael Erickson) wrote…
Ah, drat, good point.
Doubt it matters all that much, but you can make the change on master if you're up to it.
|
Oh and passing closures to packages would also make that possible. Though I guess the previous version of this code would have the same problem, so probably not something to worry about right now. |
There was a problem hiding this comment.
Reviewable status:
pkg/sql/colexecerror/error.go line 87 at r4 (raw file):
Previously, mgartner (Marcus Gartner) wrote…
Although maybe that is possible in some cases where we avoid cycles by setting global variables in a package.
Oh and passing closures to packages would also make that possible.
Though I guess the previous version of this code would have the same problem, so probably not something to worry about right now.
It's a good point, there might be some edge cases where we let the panic escape when we don't need to.
There was a problem hiding this comment.
Reviewable status:
pkg/sql/colexecerror/error.go line 88 at r4 (raw file):
Previously, mgartner (Marcus Gartner) wrote…
Doubt it matters all that much, but you can make the change on master if you're up to it.
I too had the same thought, but I think this allocation will still escape to the heap (because we pass it into another function) - IIRC I did a quick check with gcflags=-m=2 when I was reviewing the original PR.
Backport 4/4 commits from #123277 on behalf of @michae2.
/cc @cockroachdb/release
See individual commits for details.
Benchmarks before and after the change:
Fixes: #123235
Release note (performance improvement): Make error handling in the vectorized execution engine much cheaper. This should help avoid bad metastable regimes perpetuated by statement timeout handling consuming all CPU time, leading to more statement timeouts.
Co-authored-by: Drew Kimball drewk@cockroachlabs.com
Release justification: fix for serious performance issue.