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

roachtest: disk-stalled/wal-failover/among-stores failed #135983

Open
cockroach-teamcity opened this issue Nov 22, 2024 · 5 comments
Open

roachtest: disk-stalled/wal-failover/among-stores failed #135983

cockroach-teamcity opened this issue Nov 22, 2024 · 5 comments
Assignees
Labels
A-storage Relating to our storage engine (Pebble) on-disk storage. B-runtime-assertions-enabled branch-release-24.3 Used to mark GA and release blockers, technical advisories, and bugs for 24.3 C-test-failure Broken test (automatically or manually discovered). O-roachtest O-robot Originated from a bot. P-3 Issues/test failures with no fix SLA T-storage Storage Team

Comments

@cockroach-teamcity
Copy link
Member

cockroach-teamcity commented Nov 22, 2024

Note: This build has runtime assertions enabled. If the same failure was hit in a run without assertions enabled, there should be a similar failure without this message. If there isn't one, then this failure is likely due to an assertion violation or (assertion) timeout.

roachtest.disk-stalled/wal-failover/among-stores failed with artifacts on release-24.3 @ 82c427f7a58cec597a46a516a1d7d47b68296d18:

(disk_stall.go:151).runDiskStalledWALFailover: process exited unexpectedly
(cluster.go:2455).Run: context canceled
test artifacts and logs in: /artifacts/disk-stalled/wal-failover/among-stores/run_1

Parameters:

  • arch=amd64
  • cloud=gce
  • coverageBuild=false
  • cpu=16
  • encrypted=true
  • fs=ext4
  • localSSD=true
  • runtimeAssertionsBuild=true
  • ssd=2
Help

See: roachtest README

See: How To Investigate (internal)

See: Grafana

Same failure on other branches

/cc @cockroachdb/storage

This test on roachdash | Improve this report!

Jira issue: CRDB-44813

@cockroach-teamcity cockroach-teamcity added B-runtime-assertions-enabled branch-release-24.3 Used to mark GA and release blockers, technical advisories, and bugs for 24.3 C-test-failure Broken test (automatically or manually discovered). O-roachtest O-robot Originated from a bot. release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. T-storage Storage Team labels Nov 22, 2024
@blathers-crl blathers-crl bot added the A-storage Relating to our storage engine (Pebble) on-disk storage. label Nov 22, 2024
Copy link

blathers-crl bot commented Nov 22, 2024

This issue has multiple T-eam labels. Please make sure it only has one, or else issue synchronization will not work correctly.

🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.

@cockroach-teamcity
Copy link
Member Author

Note: This build has runtime assertions enabled. If the same failure was hit in a run without assertions enabled, there should be a similar failure without this message. If there isn't one, then this failure is likely due to an assertion violation or (assertion) timeout.

roachtest.disk-stalled/wal-failover/among-stores failed with artifacts on release-24.3 @ 2c6a0102b055cc6180aa32c5ee9962454b35ce4c:

(disk_stall.go:164).runDiskStalledWALFailover: unexpectedly high p99.99 latency 1.54252547s at 2024-11-23T11:00:00Z
(disk_stall.go:164).runDiskStalledWALFailover: unexpectedly high p99.99 latency 2.186540992s at 2024-11-23T11:01:00Z
(cluster.go:2455).Run: context canceled
test artifacts and logs in: /artifacts/disk-stalled/wal-failover/among-stores/run_1

Parameters:

  • arch=amd64
  • cloud=gce
  • coverageBuild=false
  • cpu=16
  • encrypted=true
  • fs=ext4
  • localSSD=true
  • runtimeAssertionsBuild=true
  • ssd=2
Help

See: roachtest README

See: How To Investigate (internal)

See: Grafana

Same failure on other branches

This test on roachdash | Improve this report!

@jbowens
Copy link
Collaborator

jbowens commented Nov 25, 2024

Most recent failure:

(disk_stall.go:164).runDiskStalledWALFailover: unexpectedly high p99.99 latency 1.54252547s at 2024-11-23T11:00:00Z
(disk_stall.go:164).runDiskStalledWALFailover: unexpectedly high p99.99 latency 2.186540992s at 2024-11-23T11:01:00Z

https://grafana.testeng.crdb.io/d/StorageAvKxELVz/storage?from=1732358188352&to=1732362351437&var-cluster=teamcity-17895377-1732344094-72-n4cpu16&orgId=1

Unclear why n1 seems to have been cpu saturated the entire time.

First failure:

2024/11/22 11:17:23 disk_stall.go:117: test status: pausing 2m1.995771852s before next simulated disk stall on n1
2024/11/22 11:18:24 disk_stall.go:117: test status: pausing 1m1.010603551s before next simulated disk stall on n1
2024/11/22 11:19:24 disk_stall.go:117: test status: pausing 990.728199ms before next simulated disk stall on n1
2024/11/22 11:19:26 cluster.go:2475: running cmd `sudo dmsetup suspend --nofl...` on nodes [:1]
2024/11/22 11:19:26 cluster.go:2477: details in run_111926.045419763_n1_sudo-dmsetup-suspend.log
2024/11/22 11:20:53 cluster.go:2475: running cmd `sudo dmsetup resume data1` on nodes [:1]
2024/11/22 11:20:53 cluster.go:2477: details in run_112053.154557363_n1_sudo-dmsetup-resume-.log
2024/11/22 11:20:54 disk_stall.go:117: test status: pausing 9m58.996684485s before next simulated disk stall on n1
2024/11/22 11:21:54 disk_stall.go:117: test status: pausing 7m32.009157141s before next simulated disk stall on n1
2024/11/22 11:22:54 disk_stall.go:117: test status: pausing 6m32.001622751s before next simulated disk stall on n1
2024/11/22 11:23:43 disk_stall.go:146: test status: exited stall loop
2024/11/22 11:23:44 cluster.go:2546: running cmd `systemctl show cockroach-sy...` on nodes [:1]; details in run_112344.046197675_n1_systemctl-show-cockr.log
2024/11/22 11:23:44 test_impl.go:455: test failure #1: full stack retained in failure_1.log: (disk_stall.go:151).runDiskStalledWALFailover: process exited unexpectedly
2024/11/22 11:23:44 cluster.go:2475: running cmd `sudo dmsetup resume data1` on nodes [:1-4]
2024/11/22 11:23:44 cluster.go:2477: details in run_112344.877552358_n1-4_sudo-dmsetup-resume-.log
2024/11/22 11:23:44 test_impl.go:455: test failure #2: full stack retained in failure_2.log: (cluster.go:2455).Run: context canceled
2024/11/22 11:23:44 test_runner.go:1321: test completed with failure(s)
cockroach exited with code 7: Fri Nov 22 11:20:55 UTC 2024
I241122 11:20:29.043039 1602 jobs/registry.go:1599 ⋮ [T1,Vsystem,n1] 1733  AUTO SPAN CONFIG RECONCILIATION job 1023017965946896385: stepping through state succeeded
E241122 11:20:29.043056 1026 server/server_sql.go:515 ⋮ [T1,Vsystem,n1] 1734  failed to run update of instance with new session ID: node unavailable; try another peer
E241122 11:20:29.043262 1602 jobs/registry.go:898 ⋮ [T1,Vsystem,n1] 1735  error getting live session: node unavailable; try another peer
W241122 11:20:29.043426 5688134 sql/stats/automatic_stats.go:963 ⋮ [T1,Vsystem,n1] 1736  failed to create statistics on table 106: create-stats: failed to read query result: query execution canceled
F241122 11:20:29.036844 5798465 storage/pebble.go:1584 ⋮ [n1,s1,pebble] 1728  disk stall detected: disk slowness detected: syncdata on file 049727.log has been ongoing for 62.0s

Looks like we took over a minute to resume the drive.

run_111926.045419763_n1_sudo-dmsetup-suspend: 2024/11/22 11:19:26 cluster.go:2479: > sudo dmsetup suspend --noflush --nolockfs data1
run_111926.045419763_n1_sudo-dmsetup-suspend: 2024/11/22 11:19:27 cluster.go:2504: > result: <ok>
run_112053.154557363_n1_sudo-dmsetup-resume-: 2024/11/22 11:20:53 cluster.go:2479: > sudo dmsetup resume data1
run_112053.154557363_n1_sudo-dmsetup-resume-: 2024/11/22 11:20:54 cluster.go:2504: > result: <ok>

@jbowens jbowens removed the release-blocker Indicates a release-blocker. Use with branch-release-2x.x label to denote which branch is blocked. label Nov 25, 2024
@jbowens jbowens self-assigned this Nov 25, 2024
@jbowens
Copy link
Collaborator

jbowens commented Nov 25, 2024

I wonder if the long duration between stalls is somehow related to the fact the disk is stalled? Like is the ssh server trying to write to the disk? That doesn't really make sense because it's a separate mount, but idk. We could refactor it such that when we stall we specify the duration and sleep in the server-side ssh session.

@cockroach-teamcity
Copy link
Member Author

Note: This build has runtime assertions enabled. If the same failure was hit in a run without assertions enabled, there should be a similar failure without this message. If there isn't one, then this failure is likely due to an assertion violation or (assertion) timeout.

roachtest.disk-stalled/wal-failover/among-stores failed with artifacts on release-24.3 @ 6b51fe4c1a5575d655bfc1e875932e252c7048d0:

(disk_stall.go:151).runDiskStalledWALFailover: process exited unexpectedly
(cluster.go:2455).Run: context canceled
test artifacts and logs in: /artifacts/disk-stalled/wal-failover/among-stores/run_1

Parameters:

  • arch=amd64
  • cloud=gce
  • coverageBuild=false
  • cpu=16
  • encrypted=true
  • fs=ext4
  • localSSD=true
  • runtimeAssertionsBuild=true
  • ssd=2
Help

See: roachtest README

See: How To Investigate (internal)

See: Grafana

Same failure on other branches

This test on roachdash | Improve this report!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-storage Relating to our storage engine (Pebble) on-disk storage. B-runtime-assertions-enabled branch-release-24.3 Used to mark GA and release blockers, technical advisories, and bugs for 24.3 C-test-failure Broken test (automatically or manually discovered). O-roachtest O-robot Originated from a bot. P-3 Issues/test failures with no fix SLA T-storage Storage Team
Projects
Status: Incoming
Development

No branches or pull requests

2 participants