oxidecomputer / oxidecomputer/crucible

During downstairs replacment and heavy load, other downstairs stopped responding

Open
#1,289 3 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
Rust
Stars
260
Forks
34
Avg merge
2d 1h
Merged PRs (30d)
8

Description

During a downstairs replacement test with heavy load from the guest, a 2nd downstairs stopped responding
and went to faulted.

The original downstairs are:

22:59:06.072Z INFO downstairs client at Some([fd00:1122:3344:101::14]:19003) has region UUID fa63da4a-cb7d-49d6-b057-0dfe65d1793f
22:59:06.072Z INFO downstairs client at Some([fd00:1122:3344:101::16]:19004) has region UUID 2d925ec8-04e1-4b12-b010-520a45cf67dd
22:59:06.073Z INFO downstairs client at Some([fd00:1122:3344:101::15]:19001) has region UUID ddaf3e3b-9745-41ee-86ca-2dfa785717d3
22:59:06.181Z INFO downstairs client at Some([fd00:1122:3344:101::14]:19000) has region UUID 001bcfd5-e7b3-4c6f-95c3-ac83765277b1
22:59:06.184Z INFO downstairs client at Some([fd00:1122:3344:101::18]:19004) has region UUID 9be5b782-522a-4117-98f7-fb8d0cb5acc2
22:59:06.185Z INFO downstairs client at Some([fd00:1122:3344:101::13]:19000) has region UUID b46dbcd3-1724-431e-95b8-6d0298fa67e3

Things start out with a replacement:

23:41:31.802Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): Volume 7c601df8-60ef-4120-b9d5-5741e57da946, OK to replace: [fd00:1122:3344:101::14]:19000 with [fd00:1122:3344:101::16]:19005
23:41:31.802Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): 7c601df8-60ef-4120-b9d5-5741e57da946 request to replace downstairs [fd00:1122:3344:101::14]:19000 with [fd00:1122:3344:101::16]:19005
23:41:31.802Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): 7c601df8-60ef-4120-b9d5-5741e57da946 found old target: [fd00:1122:3344:101::14]:19000 at 1
23:41:31.802Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): 7c601df8-60ef-4120-b9d5-5741e57da946 replacing old: [fd00:1122:3344:101::14]:19000 at 1
23:41:31.802Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [1] client skip 1419 in process jobs because fault
23:41:31.802Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [1] changed 479 jobs to fault skipped

We start repairing downstairs 1, and get through one extent:

23:41:43.809Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): Checking if live repair is needed
23:41:43.809Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): Live Repair already running
23:41:43.968Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): notified Nexus of repair start
    repair = 07c8fdd5-d681-4879-9b58-92fc65e0e4f9
23:41:44.191Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): got repair ok in Closing { close_id: JobId(2110339), repair_id: JobId(2110340), noop_id: JobId(2110341), reopen_id: JobId(2110342), gw_repair_id: GuestWorkId(2109341), gw_noop_id: GuestWorkId(2109342) }
23:41:44.192Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): RE:0 Wait for result from repair command 2110340:2109341
23:41:44.192Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): Repair for extent 0 s:2 d:[ClientId(1)]
23:41:44.885Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): got repair ok in Repairing { repair_id: JobId(2110340), noop_id: JobId(2110341), reopen_id: JobId(2110342), gw_noop_id: GuestWorkId(2109342) }
23:41:44.885Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): RE:0 Wait for result from NoOp command 2110341:2109342
23:41:46.656Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): got repair ok in Noop { noop_id: JobId(2110341), reopen_id: JobId(2110342) }
23:41:46.656Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): RE:0 Wait for result from reopen command 2110342
23:41:46.656Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): got repair ok in Reopening { reopen_id: JobId(2110342) }
23:41:46.656Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): Create new job ids for 1: ExtentRepairIDs { close_id: JobId(2113309), repair_id: JobId(2113310), noop_id: JobId(2113311), reopen_id: JobId(2113312) }
23:41:46.656Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): RE:1 repair extent with ids 2113309,2113310,2113311,2113312 deps:[JobId(2113119)]
23:41:46.657Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): new DNS resolver
    addresses = [[fd00:1122:3344:1::1]:53, [fd00:1122:3344:2::1]:53, [fd00:1122:3344:3::1]:53, [fd00:1122:3344:4::1]:53, [fd00:1122:3344:5::1]:53]
    repair = 07c8fdd5-d681-4879-9b58-92fc65e0e4f9
23:41:46.751Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): notified Nexus of repair progress
    repair = 07c8fdd5-d681-4879-9b58-92fc65e0e4f9
23:41:48.503Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): got repair ok in Closing { close_id: JobId(2113309), repair_id: JobId(2113310), noop_id: JobId(2113311), reopen_id: JobId(2113312), gw_repair_id: GuestWorkId(2112311), gw_noop_id: GuestWorkId(2112312) }
23:41:48.503Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): RE:1 Wait for result from repair command 2113310:2112311
23:41:48.503Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): Repair for extent 1 s:2 d:[ClientId(1)]
23:42:02.572Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): got repair ok in Repairing { repair_id: JobId(2113310), noop_id: JobId(2113311), reopen_id: JobId(2113312), gw_noop_id: GuestWorkId(2112312) }
23:42:02.573Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): RE:1 Wait for result from NoOp command 2113311:2112312

Then.. things seem to get stuck. Downstairs 2 no longer responds:

23:42:17.578Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): timeout 1/3 client = 2
23:42:32.580Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): timeout 2/3 client = 2
23:42:47.583Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): timeout 3/3 client = 2
23:42:47.583Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): inactivity timeout client = 2
23:42:47.583Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): client task is sending Done(Timeout) client = 2
23:42:47.583Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): downstairs task for 2 stopped due to Timeout
23:42:47.583Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): Gone missing, transition from Active to Offline client = 2
23:42:47.583Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [2] client re-new 14440 jobs since flush 2113119
23:42:47.583Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): new DNS resolver
    addresses = [[fd00:1122:3344:1::1]:53, [fd00:1122:3344:2::1]:53, [fd00:1122:3344:3::1]:53, [fd00:1122:3344:4::1]:53, [fd00:1122:3344:5::1]:53]
    downstairs_id = b46dbcd3-1724-431e-95b8-6d0298fa67e3
23:42:47.585Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [2] Marked 14440 jobs for replay since flush: 2113119
23:42:47.586Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): downstairs failed, too many outstanding jobs 14440
23:42:47.586Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [2] client skip 14440 in process jobs because fault
23:42:47.586Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [2] notify = true for 2113311
23:42:47.586Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [2] notify = true for 2113312
23:42:47.588Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [2] changed 14440 jobs to fault skipped

So downstairs 2 is ejected.
This then unravels the repair, and we kick out downstairs 1 and start the LiveRepair over

23:42:47.726Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): ds_transition from Offline to Faulted client = 2
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [2] Transition from Offline to Faulted client = 2
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): got repair ok in Noop { noop_id: JobId(2113311), reopen_id: JobId(2113312) }
23:42:47.727Z WARN propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): aborting live-repair due to invalid state
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [1] client skip 39 in process jobs because fault
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [1] changed 0 jobs to fault skipped
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): ds_transition from LiveRepair to Faulted  client = 1
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): [1] Transition from LiveRepair to Faulted  client = 1
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): RE:1 Wait for result from reopen command 2113312
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): got repair ok in Reopening { reopen_id: JobId(2113312) }
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): LiveRepair final flush submitted
23:42:47.727Z INFO propolis-server (crucible-7c601df8-60ef-4120-b9d5-5741e57da946): client task is exiting

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by tracing the LiveRepair flow and downstairs client task around the logged NoOp, reopen, timeout, and Active-to-Offline/Faulted transitions. Reproduce the replacement under heavy guest load and inspect where client 2 stops responding and why the repair state becomes invalid. Done means the failure cause is identified and a regression test or documented fix covers this sequence.

Written by the indexing model from the issue text.

Assessment

Tech stack
rust
Domain
backend, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
28/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.