roachtest: tpchvec/perf failed #46664

cockroach-teamcity · 2020-03-27T09:05:49Z

(roachtest).tpchvec/perf failed on master@c0855e9fcf979cca1094d7edeeacb9882ddc9f96:

The test failed on branch=master, cloud=gce:
test artifacts and logs in: /home/agent/work/.go/src/github.com/cockroachdb/cockroach/artifacts/20200327-1832621/tpchvec/perf/run_1
	tpchvec.go:579,tpchvec.go:660,test_runner.go:753: error with attached stack trace:
		    main.execCmdWithBuffer
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:426
		    main.(*cluster).RunWithBuffer
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2031
		    main.registerTPCHVec.func1
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tpchvec.go:574
		    main.registerTPCHVec.func2
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tpchvec.go:660
		    main.(*testRunner).runTest.func2
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/test_runner.go:753
		    runtime.goexit
		    	/usr/local/go/src/runtime/asm_amd64.s:1357
		  - error with embedded safe details: %s
		    -- arg 1: <string>
		  - /home/agent/work/.go/src/github.com/cockroachdb/cockroach/bin/roachprod run teamcity-1832621-1585293773-20-n3cpu4:1 -- ./workload run tpch --concurrency=1 --db=tpch --max-ops=3 --queries=20 --vectorize=off {pgurl:1-3}:
		  - exit status 30

More

Artifacts: /tpchvec/perf
Related:

roachtest: tpchvec/perf failed #46663 roachtest: tpchvec/perf failed C-test-failure O-roachtest O-robot branch-release-19.2 release-blocker

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

The text was updated successfully, but these errors were encountered:

asubiotto · 2020-03-27T14:23:54Z

Error: [q20]: pq: root: memory budget exceeded: 10240 bytes requested, 3940650240 currently allocated, 3940651008 bytes in budget

asubiotto · 2020-03-27T14:35:44Z

cc @yuzefovich do you think we might've introduced a memory accounting leak in a recent change?

yuzefovich · 2020-03-27T15:37:38Z

09:05:22 cluster.go:421: > /home/agent/work/.go/src/github.com/cockroachdb/cockroach/bin/roachprod run teamcity-1832621-1585293773-20-n3cpu4:1 -- ./workload run tpch --concurrency=1 --db=tpch --max-ops=3 --queries=20 --vectorize=off {pgurl:1-3}
09:05:30 tpchvec.go:575: 
Error: [q20]: pq: root: memory budget exceeded: 10240 bytes requested, 3940650240 currently allocated, 3940651008 bytes in budget

so it happened with vectorize=off, and, in fact, we fixed the memory accounting problem with rowexec. I'm not sure, though, what should we be doing now with query 20.

asubiotto · 2020-03-27T15:58:47Z

Interesting, I missed that line. It's possible that this is related to the fact that we're now properly accounting for some more hash aggregator memory? I'm seeing two surprising things:

In the memory profiles, it seems like only colexec is showing up, which doesn't seem to match up with the vecorize=off unless I'm looking at the wrong memory profiles.
In the error message it's saying that we have around 4GB but the memory profile with most memory in use is node 2 with around 500MB of in use memory:
. If the memory profiles are correct it seems like we have some memory accounting leak. This seems very hard to have in the vectorized engine, though.

yuzefovich · 2020-03-27T20:54:12Z

Yes, I believe the fix to memory accounting in hash aggregator is the reason we hit a memory limit here, and unless we messed up the fixes that went in (I'm a little concerned about the first one, about the "internal" memory of map), memory error is the expected behavior now and should have been always.

Are you looking at memprof.000000000887919168_2020-03-27T09_05_10.864.pprof? Note that this was taken at 09:05:10 which is when query 20 was executed with vectorize=on for the second (out of three) time:

I200327 09:04:57.019337 55 workload/tpch/tpch.go:465  [q20] returned 186 rows after 12.51 seconds
I200327 09:05:09.616685 55 workload/tpch/tpch.go:465  [q20] returned 186 rows after 12.60 seconds
I200327 09:05:22.168569 55 workload/tpch/tpch.go:465  [q20] returned 186 rows after 12.55 seconds

vectorize=off config started executing at 09:05:22 and hit an error at 09:05:30, and I don't think we have memory profiles for that period.

yuzefovich · 2020-03-27T20:57:42Z

I guess I don't understand how rowexec might be using 4GB while colexec seems to be using 10 times less, this deserves an investigation.

yuzefovich · 2020-03-27T21:25:01Z

Ok, I see what's happening. Here is the corresponding part of the plan when vectorize=on:

The important information to get from here is that hash aggregator outputs 540k tuples with four columns, three of which are populated using anyNotNull aggregate. We've added memory accounting for that kind of aggregate in the same way as all other aggregates are accounted for - by instantiating a memory account for each struct. Now, this results in "reserving" mon.DefaultPoolAllocation = 10240 bytes although we will only be using a single datum (likely of 8 bytes size), so the math comes out to:
540000 * 3 * 10240 bytes > 15GiB of budget we would need to have, but we only have 4GiB, so we will error out.

I left reusing the same account as a TODO because I thought it would be too invasive of a change at this point (plus would be harder to backport), but it seems like now it could be considered a release blocker since we're likely to error out on OLAP-y queries with rowexec aggregation when, in fact, we do have enough RAM to succeed. cc @jordanlewis for your opinion on this.

yuzefovich · 2020-03-28T02:38:14Z

cc @rohany it is possible that alterpk-tpcc will error out with a memory limit error until this issue is resolved.

cockroach-teamcity · 2020-03-28T12:18:18Z

(roachtest).tpchvec/perf failed on master@0e9f07ae35ad39e8789bc51c49066c123968a666:

The test failed on branch=master, cloud=gce:
test artifacts and logs in: /home/agent/work/.go/src/github.com/cockroachdb/cockroach/artifacts/20200328-1834610/tpchvec/perf/run_1
	tpchvec.go:579,tpchvec.go:660,test_runner.go:753: error with attached stack trace:
		    main.execCmdWithBuffer
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:426
		    main.(*cluster).RunWithBuffer
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2031
		    main.registerTPCHVec.func1
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tpchvec.go:574
		    main.registerTPCHVec.func2
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tpchvec.go:660
		    main.(*testRunner).runTest.func2
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/test_runner.go:753
		    runtime.goexit
		    	/usr/local/go/src/runtime/asm_amd64.s:1357
		  - error with embedded safe details: %s
		    -- arg 1: <string>
		  - /home/agent/work/.go/src/github.com/cockroachdb/cockroach/bin/roachprod run teamcity-1834610-1585381212-21-n3cpu4:1 -- ./workload run tpch --concurrency=1 --db=tpch --max-ops=3 --queries=20 --vectorize=off {pgurl:1-3}:
		  - exit status 30

More

Artifacts: /tpchvec/perf
Related:

roachtest: tpchvec/perf failed #46663 roachtest: tpchvec/perf failed C-test-failure O-roachtest O-robot branch-release-19.2 release-blocker

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

cockroach-teamcity · 2020-03-29T09:13:08Z

(roachtest).tpchvec/perf failed on master@92495ffb2182671b3338a8c6cd2734cb6de5d392:

The test failed on branch=master, cloud=gce:
test artifacts and logs in: /home/agent/work/.go/src/github.com/cockroachdb/cockroach/artifacts/20200329-1836230/tpchvec/perf/run_1
	tpchvec.go:579,tpchvec.go:660,test_runner.go:753: error with attached stack trace:
		    main.execCmdWithBuffer
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:426
		    main.(*cluster).RunWithBuffer
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2031
		    main.registerTPCHVec.func1
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tpchvec.go:574
		    main.registerTPCHVec.func2
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/tpchvec.go:660
		    main.(*testRunner).runTest.func2
		    	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/test_runner.go:753
		    runtime.goexit
		    	/usr/local/go/src/runtime/asm_amd64.s:1357
		  - error with embedded safe details: %s
		    -- arg 1: <string>
		  - /home/agent/work/.go/src/github.com/cockroachdb/cockroach/bin/roachprod run teamcity-1836230-1585466755-20-n3cpu4:1 -- ./workload run tpch --concurrency=1 --db=tpch --max-ops=3 --queries=20 --vectorize=off {pgurl:1-3}:
		  - exit status 30

More

Artifacts: /tpchvec/perf
Related:

roachtest: tpchvec/perf failed #46663 roachtest: tpchvec/perf failed C-test-failure O-roachtest O-robot branch-release-19.2 release-blocker

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

asubiotto · 2020-03-30T08:50:04Z

Good catch. 540k groups is crazy...

cockroach-teamcity added this to the 20.1 milestone Mar 27, 2020

cockroach-teamcity assigned andreimatei Mar 27, 2020

asubiotto unassigned andreimatei Mar 27, 2020

yuzefovich mentioned this issue Mar 27, 2020

release-19.2: sem/builtins: account for internal memory of some aggregates #46622

Merged

yuzefovich self-assigned this Mar 27, 2020

yuzefovich mentioned this issue Mar 27, 2020

sql: make aggregate builtins share the same memory account #46700

Merged

jordanlewis mentioned this issue Mar 30, 2020

20.1 release blockers list #45599

Closed

83 tasks

cockroach-teamcity mentioned this issue Mar 31, 2020

roachtest: tpchvec/perf failed #46781

Closed

craig bot closed this as completed in 1320e13 Mar 31, 2020

This was referenced Mar 31, 2020

release-20.1: sql: make aggregate builtins share the same memory account #46816

Merged

release-19.2: sql: make aggregate builtins share the same memory account #46817

Merged

yuzefovich mentioned this issue Sep 30, 2022

rowexec: fix usage of the shared "single datum" acc in windower #89050

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

roachtest: tpchvec/perf failed #46664

roachtest: tpchvec/perf failed #46664

cockroach-teamcity commented Mar 27, 2020

asubiotto commented Mar 27, 2020

asubiotto commented Mar 27, 2020

yuzefovich commented Mar 27, 2020

asubiotto commented Mar 27, 2020

yuzefovich commented Mar 27, 2020

yuzefovich commented Mar 27, 2020

yuzefovich commented Mar 27, 2020

yuzefovich commented Mar 28, 2020

cockroach-teamcity commented Mar 28, 2020

cockroach-teamcity commented Mar 29, 2020

asubiotto commented Mar 30, 2020

roachtest: tpchvec/perf failed #46664

roachtest: tpchvec/perf failed #46664

Comments

cockroach-teamcity commented Mar 27, 2020

asubiotto commented Mar 27, 2020

asubiotto commented Mar 27, 2020

yuzefovich commented Mar 27, 2020

asubiotto commented Mar 27, 2020

yuzefovich commented Mar 27, 2020

yuzefovich commented Mar 27, 2020

yuzefovich commented Mar 27, 2020

yuzefovich commented Mar 28, 2020

cockroach-teamcity commented Mar 28, 2020

cockroach-teamcity commented Mar 29, 2020

asubiotto commented Mar 30, 2020