A downstairs region reports missing context slot

[leftwo]

My instance on dogfood was stuck in starting.

Looking in the propolis log, I found it was waiting for one of the downstairs to come online after being told to activate:

21:24:22.961Z INFO propolis-server (vm_state_driver): connecting to [fd00:1122:3344:106::d]:19033
     = downstairs
    client = 1
    session_id = 303bf55e-2b8e-44a5-a521-c8eac984801a
21:24:22.961Z WARN propolis-server (vm_state_driver): ds_connection connect to [fd00:1122:3344:106:
:d]:19033 failure: Os { code: 146, kind: ConnectionRefused, message: "Connection refused" }
     = downstairs
    client = 1
    session_id = 303bf55e-2b8e-44a5-a521-c8eac984801a

There is only one disk on my instance, so it was easy enough to find it's ID.
Dumping info about it tells me where the what the region IDs are, which sled contains them, and all the IPs of the downstairs:

root@oxz_switch0:~# omdb db disks info bfa68c2e-ad75-4793-88eb-05c48527f567
HOST_SERIAL DISK_NAME                        INSTANCE_NAME PROPOLIS_ZONE                                            VOLUME_ID
                           DISK_STATE IMPORT_ADDRESS READONLY
BRM42220031 nightlydebug-btrium-image-1190c3 nightlydebug  oxz_propolis-server_9c447451-23b0-405e-b705-1cce40b4427e b5f12294- 414-4308-a959-0367b846664b attached   -              false
HOST_SERIAL REGION                               DATASET                              PHYSICAL_DISK
BRM27230045 8915bf83-b1e8-4782-8526-31530f6a4b79 7cdb3c11-f792-4195-9152-16a948fb271e 1f938f43-7003-4c9b-b961-0b9c1a7fecbe
BRM13250012 bc095a4b-3b8b-47fe-a660-b380a55c7b74 8aaf6a36-a2fc-4ce8-9372-888bc20854b1 4b75f4a4-22c6-4391-b0e1-b1c101f7ebbb
BRM42220006 2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe fffddf56-10ca-4b62-9be3-5b3764a5f682 7e6e461b-c246-4b88-bcc8-28f0d9f5495e
VCR from volume ID b5f12294-e414-4308-a959-0367b846664b
ID                                   BS  SUB_VOLUMES READ_ONLY_PARENT
bfa68c2e-ad75-4793-88eb-05c48527f567 512 1           false

SUB VOLUME 0
    ID                                   BS  BPE    EC   GENERATION READ_ONLY 
    bfa68c2e-ad75-4793-88eb-05c48527f567 512 131072 4016 10         false
    [fd00:1122:3344:129::22]:19004
    [fd00:1122:3344:106::d]:19033
    [fd00:1122:3344:127::29]:19023

I know my downstairs has this IP: [fd00:1122:3344:106::d], so I just need to figure out which sled has fd00:1122:3344:106 and then which crucible region of the three above matches.

root@oxz_switch0:~# pilot host exec -c "ipadm | grep fd00 | grep sled6" 0-31
 2  BRM22250001        ok: underlay0/sled6   static   ok           fd00:1122:3344:128::1/64
 3  BRM13250012        ok: underlay0/sled6   static   ok           fd00:1122:3344:129::1/64
 7  BRM27230045        ok: underlay0/sled6   static   ok           fd00:1122:3344:127::1/64
 8  BRM44220011        ok: underlay0/sled6   static   ok           fd00:1122:3344:103::1/64
 9  BRM44220005        ok: underlay0/sled6   static   ok           fd00:1122:3344:105::1/64
10  BRM42220009        ok: underlay0/sled6   static   ok           fd00:1122:3344:107::1/64
11  BRM42220006        ok: underlay0/sled6   static   ok           fd00:1122:3344:106::1/64
12  BRM42220057        ok: underlay0/sled6   static   ok           fd00:1122:3344:104::1/64
14  BRM42220051        ok: underlay0/sled6   static   ok           fd00:1122:3344:10b::1/64
16  BRM42220014        ok: underlay0/sled6   static   ok           fd00:1122:3344:108::1/64
17  BRM42220017        ok: underlay0/sled6   static   ok           fd00:1122:3344:109::1/64
21  BRM42220031        ok: underlay0/sled6   static   ok           fd00:1122:3344:102::1/64
23  BRM42220016        ok: underlay0/sled6   static   ok           fd00:1122:3344:10a::1/64
25  BRM44220010        ok: underlay0/sled6   static   ok           fd00:1122:3344:101::1/64

So, sled 11 has our bad downstairs, BRM13250012. This is region bc095a4b-3b8b-47fe-a660-b380a55c7b74
Sleds - region lookup:

03 BRM13250012 bc095a4b-3b8b-47fe-a660-b380a55c7b74 
07 BRM27230045 8915bf83-b1e8-4782-8526-31530f6a4b79 
11 BRM42220006 2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe <------ problem

On sled 11, we can find our zone a few ways, but this work by searching for IP:

BRM42220006 # for zzz in $(zoneadm list | grep crucible); do  echo -n "$zzz "; zlogin $zzz ipadm | grep fd00; done
oxz_crucible_0022703b-dcfc-44d4-897a-b42f6f53b433 oxControlService13/omicron6 static ok   fd00:1122:3344:106::c/64
oxz_crucible_12afe1c3-bfe6-4278-8240-91d401347d36 oxControlService14/omicron6 static ok   fd00:1122:3344:106::8/64
oxz_crucible_46d1afcc-cc3f-4b17-aafc-054dd4862d15 oxControlService15/omicron6 static ok   fd00:1122:3344:106::5/64
oxz_crucible_605be8b9-c652-4a5f-94ca-068ec7a39472 oxControlService17/omicron6 static ok   fd00:1122:3344:106::a/64
oxz_crucible_65b3db59-9361-4100-9cee-04e32a8c67d3 oxControlService18/omicron6 static ok   fd00:1122:3344:106::7/64
oxz_crucible_9b8194ee-917d-4abc-a55c-94cea6cdaea1 oxControlService20/omicron6 static ok   fd00:1122:3344:106::6/64
oxz_crucible_af8a8712-457c-4ea7-a8b6-aecb04761c1b oxControlService21/omicron6 static ok   fd00:1122:3344:106::9/64
oxz_crucible_b369e133-485c-4d98-8fee-83542d1fd94d oxControlService22/omicron6 static ok   fd00:1122:3344:106::4/64
oxz_crucible_c33b5912-9985-43ed-98f2-41297e2b796a oxControlService23/omicron6 static ok   fd00:1122:3344:106::b/64
oxz_crucible_pantry_e9ea27c2-600a-45fb-9224-36eca95d87b6 oxControlService24/omicron6 static ok   fd00:1122:3344:106::74/64
oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682 oxControlService25/omicron6 static ok   fd00:1122:3344:106::d/64  <---- our IP

Inside the zone, let's find the logs from that downstairs:

zlogin oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682
root@oxz_crucible_fffddf56:~# svcs | grep 2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe
online         21:35:00 svc:/oxide/crucible/downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe
root@oxz_crucible_fffddf56:~# tail -f $(svcs -L svc:/oxide/crucible/downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe)
[ Mar 13 21:35:10 Executing start method ("/opt/oxide/lib/svc/manifest/crucible/downstairs.sh"). ]
{"msg":"Opened existing region file \"/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/region.json\"","v":0,"name":"crucible","level":30,"time":"2026-03-13T21:35:10.992893765Z","hostname":"oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682","pid":4923}
{"msg":"Database read version 1","v":0,"name":"crucible","level":30,"time":"2026-03-13T21:35:10.993166652Z","hostname":"oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682","pid":4923}
{"msg":"Database write version 1","v":0,"name":"crucible","level":30,"time":"2026-03-13T21:35:10.993178104Z","hostname":"oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682","pid":4923}
Error: missing context slot for block 58607 in extent 2799
[ Mar 13 21:35:12 Stopping because service exited with an error. ]

And, we have our problem, no context for a block: Error: missing context slot for block 58607 in extent 2799

This will cause the downstairs service to exit (and restart) and will prevent the upstairs from ever connecting to it.

[leftwo]

The failing extent reports:

root@oxz_crucible_fffddf56:/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000# /tmp/crucible-verify-raw AEF
bs:512 bytes  bc:131072  dirty: true gen:4 flush_number:37009787 ext_ver:2 bonus_sync:21543 defrag:939
Error at block 58607:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58608:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58609:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58610:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58611:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58612:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58613:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58614:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58615:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58616:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58617:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58618:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58619:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58620:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58621:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58622:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error at block 58623:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338
Error: verification failed, see logs for details

Where as the same extent on other downstairs reports:

root@oxz_crucible_dcdeb44b:/data/regions/bc095a4b-3b8b-47fe-a660-b380a55c7b74/00/000# /tmp/crucible-verify-raw AEF
bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37394626 ext_ver:2 bonus_sync:21760 defrag:957

Of interest, the bad extent appears older than the valid extent, flush 37009787 vs. flush 37394626

I've put copies of extents AEE and AEF in /staff/core/crucible-1906 in sled named directories.
I threw AEE in there to have a good extent to compare with.

[leftwo]

Looking at surrounding extents with crucible-verify-raw, I can see a difference between good extents on BRM13250012 (sled 3):

AE7 bs:512 bytes  bc:131072  dirty:false gen:2 flush_number:1572812 ext_ver:2 bonus_sync:0 defrag:0                         
AE8 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37382027 ext_ver:2 bonus_sync:6100 defrag:132  
AE9 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37395261 ext_ver:2 bonus_sync:118088 defrag:962
AEA bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37389881 ext_ver:2 bonus_sync:13054 defrag:629
AEB bs:512 bytes  bc:131072  dirty:false gen:2 flush_number:1573420 ext_ver:2 bonus_sync:0 defrag:0        
AEC bs:512 bytes  bc:131072  dirty:false gen:2 flush_number:1573468 ext_ver:2 bonus_sync:0 defrag:0        
AED bs:512 bytes  bc:131072  dirty:false gen:2 flush_number:1573812 ext_ver:2 bonus_sync:0 defrag:0      
AEE bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37394607 ext_ver:2 bonus_sync:11001 defrag:848 
AEF bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37394626 ext_ver:2 bonus_sync:21760 defrag:957                  
AF0 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37392327 ext_ver:2 bonus_sync:15372 defrag:508 
AF1 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:22077817 ext_ver:2 bonus_sync:16242 defrag:165                  
AF2 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37395259 ext_ver:2 bonus_sync:12113 defrag:122                  
AF3 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37395261 ext_ver:2 bonus_sync:102800 defrag:259   

And the extents on BRM42220006, (sled 11) which has the failing extent, AEF:

AE7 bs:512 bytes  bc:131072  dirty:false gen:2 flush_number:1572812 ext_ver:2 bonus_sync:0 defrag:0                       
AE8 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37013604 ext_ver:2 bonus_sync:5967 defrag:129                 
AE9 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37013605 ext_ver:2 bonus_sync:116302 defrag:947               
AEA bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37012025 ext_ver:2 bonus_sync:12801 defrag:619                
AEB bs:512 bytes  bc:131072  dirty:false gen:2 flush_number:1573420 ext_ver:2 bonus_sync:0 defrag:0                       
AEC bs:512 bytes  bc:131072  dirty:false gen:2 flush_number:1573468 ext_ver:2 bonus_sync:0 defrag:0                       
AED bs:512 bytes  bc:131072  dirty:false gen:2 flush_number:1573812 ext_ver:2 bonus_sync:0 defrag:0                       
AEE bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37009748 ext_ver:2 bonus_sync:10766 defrag:828                
AEF bs:512 bytes  bc:131072  dirty: true gen:4 flush_number:37009787 ext_ver:2 bonus_sync:21543 defrag:939                
Error at block 58607:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58608:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58609:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58610:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58611:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58612:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58613:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58614:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58615:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58616:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58617:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58618:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58619:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58620:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58621:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58622:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error at block 58623:  slot A: SlotHashMismatch, flush id: 45316 | slot B: SlotHashMismatch, flush id: 46338              
Error: verification failed, see logs for details                                                                          
AF0 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37008591 ext_ver:2 bonus_sync:15269 defrag:502                
AF1 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:22077817 ext_ver:2 bonus_sync:16242 defrag:165                
AF2 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37010489 ext_ver:2 bonus_sync:11917 defrag:122                
AF3 bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37013605 ext_ver:2 bonus_sync:101225 defrag:255

[leftwo]

When looking at the previous comment, all the extents shown are either the same or older on BRM42220006, the sled with the bad extent. This suggests there was a time where the upstairs was running with 2/3 downstairs and BRM42220006 region has fallen behind.

[leftwo]

I've copied all the downstairs log file from sled 11 where the failing downstairs is located.
Logs from the downstairs are here: /staff/core/crucible-1906/BRM42220006/downstairs-logs

Searching through them, I find this log, oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771894983, from 2/24/26 has contents where it looks like we have completed a repair to this extent:

alan@atrium:downstairs-logs$ tail oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771894983 | looker -o long
2026-02-24 01:03:02.738Z WARN crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: 16405394 job ELiveReopen waiting on 1 deps
    role = work
    upstairs_id = bfa68c2e-ad75-4793-88eb-05c48527f567
2026-02-24 01:03:02.740Z WARN crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: 16405398 job ELiveReopen waiting on 1 deps
    role = work
    upstairs_id = bfa68c2e-ad75-4793-88eb-05c48527f567
2026-02-24 01:03:02.741Z WARN crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: 16405402 job ELiveReopen waiting on 1 deps
    role = work
    upstairs_id = bfa68c2e-ad75-4793-88eb-05c48527f567
2026-02-24 01:03:02.742Z INFO crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: Created copy dir "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.copy"
2026-02-24 01:03:02.742Z INFO crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: eid:4015 Found repair files: ["FAF"]
2026-02-24 01:03:03.144Z INFO crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: Verify extent 4015 still ready for copy
2026-02-24 01:03:03.145Z INFO crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: 1 repair files downloaded, move directory "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.copy" to "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.replace"
2026-02-24 01:03:03.145Z INFO crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: Copy files from "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.replace" in "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000"
2026-02-24 01:03:03.249Z INFO crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: Move directory  "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.replace" to "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.completed"
2026-02-24 01:03:03.261Z WARN crucible/14403 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: 16405457 job Flush waiting on 1 deps
    role = work
    upstairs_id = bfa68c2e-ad75-4793-88eb-05c48527f567

Then, for much of the next hours, the log files are all empty.
The next log with output is from 2/25/26 at 21:38, where we have discovered the failed extent:

alan@atrium:downstairs-logs$ head oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1772055899 | looker -o long
[ Feb 25 21:38:06 Enabled. ]
[ Feb 25 21:38:06 Executing start method ("/opt/oxide/lib/svc/manifest/crucible/downstairs.sh"). ]
2026-02-25 21:38:06.978Z INFO crucible/13411 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: Opened existing region file "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/region.json"
2026-02-25 21:38:06.980Z INFO crucible/13411 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: Database read version 1
2026-02-25 21:38:06.980Z INFO crucible/13411 on oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682: Database write version 1
Error: missing context slot for block 58607 in extent 2799
[ Feb 25 21:38:16 Stopping because service exited with an error. ]

This at least gives us a date/time where the bad block was first detected, Feb 25 21:38:06.

[leftwo]

This instance has a local disk as well as the crucible disk. This means the instance will always be started on the same sled, as it needs to be located in the same sled as the local storage.

== VMM HISTORY =================================================================
ID                                   STATE        GEN SLED_ID                              TIME_CREATED             TIME_DELETED
9c447451-23b0-405e-b705-1cce40b4427e starting     3   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-03-13T21:21:52.780Z -
cfc8307c-1394-4d17-aaf6-5c9b2980240d saga_unwound 2   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-03-12T23:23:03.605Z 2026-03-12T23:23:15.681Z
610ebc45-282b-4202-801b-95006231dabf failed       4   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-03-10T19:02:28.200Z 2026-03-12T23:20:33.820Z
8866cb8e-de32-4829-b3ec-93f9b2277eac destroyed    7   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-03-09T23:33:50.149Z 2026-03-10T19:02:23.574Z
86161156-3c89-4615-813c-96851d1a85d4 saga_unwound 2   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-03-06T19:05:50.044Z 2026-03-06T19:06:02.202Z
e09994e2-f99f-4623-8dcf-edbc7c38acd7 failed       4   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-03-03T00:01:39.367Z 2026-03-06T19:05:45.059Z
d198d0d5-bfd4-4438-9192-27a1ae5ff0e4 failed       5   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-02-25T22:24:34.048Z 2026-03-03T00:01:32.007Z
dd22643b-9b14-42da-b2b2-d9ba89405190 failed       5   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-02-23T21:27:37.965Z 2026-02-25T22:22:23.819Z
34642336-b25e-4aeb-a43f-15ec39e342e6 failed       5   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-02-23T21:15:32.811Z 2026-02-23T21:25:06.204Z
baf68f05-dc43-4118-9d1e-d8963915af61 failed       6   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-02-19T21:11:37.383Z 2026-02-23T21:13:11.487Z
8125f7d1-8dd4-40e1-b1cc-072eb9d7ad1b failed       5   a2adea92-b56e-44fc-8a0d-7d63b5fd3b93 2026-02-19T18:16:26.606Z 2026-02-19T21:11:34.907Z

I'm gathering the logs for propolis from all these instances. Each one will have a different propolis-server UUID:
The logs will end up in /staff/core/crucible-1906/BRM42220031/oxz_propolis-server_UUID

[leftwo]

On the failed downstairs region, the most recently modified file is our bad extent:

root@oxz_crucible_fffddf56:/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000# ls -ltr | tail -10
-rw-r--r--   1 root     root     79708192 Feb 25 21:31 AFC
-rw-r--r--   1 root     root     79708192 Feb 25 21:31 B0E   
-rw-r--r--   1 root     root     79708192 Feb 25 21:31 B0F   
-rw-r--r--   1 root     root     79708192 Feb 25 21:31 B11
-rw-r--r--   1 root     root     79708192 Feb 25 21:31 004
-rw-r--r--   1 root     root     79708192 Feb 25 21:31 FAF
-rw-r--r--   1 root     root     79708192 Feb 25 21:38 B03
-rw-r--r--   1 root     root     79708192 Feb 25 21:38 B04
-rw-r--r--   1 root     root     79708192 Feb 25 21:38 B02
-rw-r--r--   1 root     root     79708192 Feb 25 21:38 AEF

[leftwo]

A dump of all the blocks in extent AEF that don't match the hash show what appears to be random data.

alan@atrium:BRM42220006$ for block in {58607..58623}; do echo "BLOCK: $block";dd if=./AEF bs=512 skip="$block" c
ount=1 2> /dev/null | od -A x -t x1 -v; done                                                                    
BLOCK: 58607                                                                                                    
0000000 f0 62 fd f7 0b 39 ef 8c 3e b1 73 29 1f 88 7e 7b                                                         
0000010 b0 53 39 3e 1c 29 61 c2 cf 71 c7 bb 6c 39 54 61                                                         
0000020 11 9e 4c 21 f1 2a a3 49 ff 3e 45 4f 1f 10 b9 bc                                                         
0000030 f6 91 27 06 06 7d 8a ff 88 e2 07 ca f9 4f 4f d4                                                         
0000040 45 86 b5 7d 44 77 77 38 6c df f1 3b 85 48 ca 39                                                         
0000050 c9 50 23 e1 2f f9 1b 06 e3 dd 09 09 df c4 18 b0                                                         
0000060 cc 82 f3 07 30 fa a3 cc f3 d7 a3 61 15 fe 78 5d                                                         
0000070 3c dc e7 1a 44 2a dd 1f 1b 61 8d a2 fc 3d 8d 2d                                                         
0000080 68 d9 76 a9 19 10 e4 f8 5a 04 3b d2 42 fb 11 ad                                                         
0000090 d8 ba e5 b3 ad 0f 89 91 ac c9 fe ef e5 da 0c e6                                                         
00000a0 28 0b 67 60 f5 c1 a8 6c be e4 50 d1 b3 0d ef 99                                                         
00000b0 ab 4f af 6d 6c cc e7 4d 04 c8 0d 14 19 1d a5 13                                                         
00000c0 f6 fb af ae cc ff f9 f3 c7 d7 07 28 a8 07 60 a8                                                         
00000d0 07 b6 37 29 c7 10 14 a5 e6 a7 e8 fd 6e 27 06 dd                                                         
00000e0 22 ae 68 0d aa 5b bc a7 23 8a 05 d5 0b 3a 84 51                                                         
00000f0 a9 45 0a 87 2e 2b 52 f6 17 8c 83 d9 24 00 5a 1c                                                         
0000100 fe 78 00 85 5c 15 78 98 18 7b b5 ad 2b 9f 89 a1                                                         
0000110 d8 67 32 83 47 9e 9b 09 59 54 1a 76 8a cb a0 ef                                                         
0000120 0e 39 ab 36 c8 0c 12 7e 5b b8 80 a1 80 8e 84 3e                                                         
0000130 b5 8f 88 a5 eb 25 ef 62 0d c9 79 ff 59 b5 69 15
0000140 c7 fe 80 a0 46 40 71 63 b2 08 58 79 2a c4 c6 61 
0000150 0d 74 0f 21 bb d1 f2 14 de e9 84 d7 b5 cd 35 66 
0000160 34 57 a3 41 a8 9a 2a d7 42 72 6c d5 86 00 f8 2f 
0000170 56 54 24 a9 ca 4e 67 4e 03 20 bf 27 98 d9 bb 87 
0000180 30 28 e7 03 20 b9 f9 89 22 44 0d ec 98 ba 8a db 
0000190 39 48 85 a0 e2 0b be 5f 08 25 aa 96 d9 2d 7d e1 
00001a0 4a 07 fc 1e 4a de 8c c0 72 ef 59 8d 80 19 1d e6
00001b0 03 53 bd ff 38 34 f5 db 17 3f b6 1c 88 17 ef 42
00001c0 02 4a 4c 1b 00 42 0a 38 4b bb ab d7 e2 ab 4e cd
00001d0 ad c1 ec 0a c3 d3 ab b6 5d bb e8 e1 35 40 eb 31 
00001e0 94 a9 c0 89 2a b8 a9 e8 68 32 4e da c8 55 aa 14 
00001f0 9d 47 09 85 6b f8 d1 8b 96 34 f7 0d 75 55 6b 82 
0000200                                                 

All the bad block data is dumped at `/staff/core/crucible-1906/BRM42220006/dump-of-bad-blocks-data.txt`

[leftwo]

I've walked all the propolis and downstairs logs that lead up to this event.
Client 1 is the eventual client that has a problem with extent 2799.
Here I've traced all the comings and goings of downstairs, live repair of extent 2799.
There is a shorter summary at the end.

Propolis server, running instance log starts
File /pool/ext/69f0b863-f73f-42b2-9822-b2cb99f09003/crypt/debug/oxz_propolis-server_dd22643b-9b14-42da-b2b2-d9ba89405190/system-illumos-propolis-server:default.log.1771882197

[ Feb 23 21:27:50 Enabled. ]

Our three downstairs connect:

2026-02-23 21:27:53.160Z INFO propolis-server: downstairs client at Some([fd00:1122:3344:129::22]:19004) has region UUID bc095a4b-3b8b-47fe-a660-b380a55c7b74 client = 0
2026-02-23 21:27:53.160Z INFO propolis-server: downstairs client at Some([fd00:1122:3344:106::d]:19033) has region UUID 2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe client = 1
2026-02-23 21:27:53.160Z INFO propolis-server: downstairs client at Some([fd00:1122:3344:127::29]:19023) has region UUID 8915bf83-b1e8-4782-8526-31530f6a4b79 client = 2

No repair required:

2026-02-23 21:27:56.363Z INFO propolis-server: Next flush: 13394619
2026-02-23 21:27:56.363Z INFO propolis-server: All extents match
2026-02-23 21:27:56.363Z INFO propolis-server: No downstairs reconciliation required
2026-02-23 21:27:56.363Z INFO propolis-server: All required reconciliation work is completed
2026-02-23 21:27:56.363Z INFO propolis-server: Set Downstairs and Upstairs active after reconciliation
2026-02-23 21:27:56.363Z INFO propolis-server: bfa68c2e-ad75-4793-88eb-05c48527f567 is now active with session: 473a94b4-9f57-42c9-b5d8-07042da3b224

Downstairs 0 stops responding, fails (not the client with the eventual problem):

2026-02-23 22:35:49.352Z WARN propolis-server: inactivity timeout client = 0

Downstairs 0 comes back, looks to repair:

2026-02-23 22:39:17.287Z INFO propolis-server: ds_connection connected from Ok([fd00:1122:3344:102::1:1163]:51782) client = 0
2026-02-23 22:39:17.288Z INFO propolis-server: downstairs client at Some([fd00:1122:3344:129::22]:19004) has region UUID bc095a4b-3b8b-47fe-a660-b380a55c7b74 client = 0
2026-02-23 22:39:17.522Z INFO propolis-server: client 0 is ready for live-repair

We do live repair extent 2799, AEF among other results..

2026-02-23 22:39:49.395Z INFO propolis-server: Create new job ids for 2799: ExtentRepairIDs { close_id: JobId(4927823), repair_id: JobId(4927824), noop_id: JobId(4927825), reopen_id: JobId(4927826) }
2026-02-23 22:39:49.395Z INFO propolis-server: RE:2799 repair extent with ids 4927823,4927824,4927825,4927826 deps:[[JobId(4927822)]]
2026-02-23 22:39:49.410Z INFO propolis-server: Repair for extent 2799 s:2 d:[ClientId(0)]
2026-02-23 22:39:49.856Z INFO propolis-server: got repair ok in Reopening { reopen_job: PendingJob { id: JobId(4927826), result: None } }

Live repair finishes:

2026-02-23 22:39:59.280Z INFO propolis-server: got repair ok in FinalFlush { flush_job: PendingJob { id: JobId(4936350), result: None } }
2026-02-23 22:39:59.280Z INFO propolis-server: LiveRepair final flush returned Ok(())
2026-02-23 22:39:59.280Z INFO propolis-server: live-repair completed successfully

Downstairs client 0 goes away again!

2026-02-23 22:46:41.388Z WARN propolis-server: inactivity timeout client = 0
2026-02-23 22:46:41.388Z WARN propolis-server: downstairs failed, too many outstanding bytes 78602240

Downstairs 0 comes back, and we LR again:

2026-02-23 22:52:11.438Z INFO propolis-server: downstairs client at Some([fd00:1122:3344:129::22]:19004) has region UUID bc095a4b-3b8b-47fe-a660-b380a55c7b74 client = 0
2026-02-23 22:52:11.438Z INFO propolis-server: Returning UUID:bc095a4b-3b8b-47fe-a660-b380a55c7b74 matches client = 0
2026-02-23 22:52:11.510Z INFO propolis-server: client 0 is ready for live-repair

We (again) live repair out bad extent:

2026-02-23 22:52:42.099Z INFO propolis-server: Create new job ids for 2799: ExtentRepairIDs { close_id: JobId(5842152), repair_id: JobId(5842153), noop_id: JobId(5842154), reopen_id: JobId(5842155) }
2026-02-23 22:52:42.099Z INFO propolis-server: RE:2799 repair extent with ids 5842152,5842153,5842154,5842155 deps:[[JobId(5842149)]]
2026-02-23 22:52:42.116Z INFO propolis-server: got repair ok in Closing { close_job: PendingJob { id: JobId(5842152), result: None }, repair_job: PendingJob { id: JobId(5842153), result: None }, noop_job: PendingJob { id: JobI(5842154), result: None }, reopen_job: PendingJob { id: JobId(5842155), result: None } }
2026-02-23 22:52:42.588Z INFO propolis-server: got repair ok in Reopening { reopen_job: PendingJob { id: JobId(5842155), result: None } }

We finish this repair of client 0:

2026-02-23 22:52:51.019Z INFO propolis-server: LiveRepair final flush submitted
2026-02-23 22:52:51.019Z INFO propolis-server: LiveRepair final flush returned Ok(())
2026-02-23 22:52:51.019Z INFO propolis-server: live-repair completed successfully

Downstairs 0 goes away again:

2026-02-24 00:28:54.885Z WARN propolis-server: downstairs disconnected client = 0

But, comes right back and does a replay here

2026-02-24 00:29:04.887Z INFO propolis-server: downstairs client at Some([fd00:1122:3344:129::22]:19004) has region UUID bc095a4b-3b8b-47fe-a660-b380a55c7b74 client = 0
2026-02-24 00:29:04.887Z INFO propolis-server: Returning UUID:bc095a4b-3b8b-47fe-a660-b380a55c7b74 matches client = 0
2026-02-24 00:29:04.887Z INFO propolis-server: send last flush ID to this DS: Some(JobId(13711089)) client = 0
2026-02-24 00:29:04.887Z INFO propolis-server: Transition from Offline to Active client = 0
2026-02-24 00:29:04.887Z INFO propolis-server: [0] client re-new 418 jobs since flush Some(JobId(13711089))
2026-02-24 00:29:04.887Z INFO propolis-server: [0] Replayed 418 jobs since flush: Some(JobId(13711089))

We don't actually know if the replay touched extent 2799, but I'm including it here so we have all the data.

Client 2 goes away:

2026-02-24 00:35:33.557Z WARN propolis-server: downstairs disconnected client = 2
2026-02-24 00:35:33.558Z WARN propolis-server: downstairs task for 2 stopped due to Finished
2026-02-24 00:35:33.893Z WARN propolis-server: downstairs failed, too many outstanding bytes 52487168

Client 2 comes back:

2026-02-24 00:35:55.164Z INFO propolis-server: downstairs client at Some([fd00:1122:3344:127::29]:19023) has region UUID 8915bf83-b1e8-4782-8526-31530f6a4b79 client = 2
2026-02-24 00:35:55.164Z INFO propolis-server: Returning UUID:8915bf83-b1e8-4782-8526-31530f6a4b79 matches client = 2
2026-02-24 00:35:55.525Z INFO propolis-server: client 2 is ready for live-repair

Our 2799 extent is repaired:

2026-02-24 00:36:14.984Z INFO propolis-server: Create new job ids for 2799: ExtentRepairIDs { close_id: JobId(14295313), repair_id: JobId(14295314), noop_id: JobId(14295315), reopen_id: JobId(14295316) }
2026-02-24 00:36:14.984Z INFO propolis-server: RE:2799 repair extent with ids 14295313,14295314,14295315,14295316 deps:[[JobId(14295312)]]
2026-02-24 00:36:14.984Z INFO propolis-server: Repair for extent 2799 s:1 d:[ClientId(2)]

Client 2 Live Repair Finishes

2026-02-24 00:36:33.809Z INFO propolis-server: LiveRepair final flush submitted
2026-02-24 00:36:33.809Z INFO propolis-server: got repair ok in FinalFlush { flush_job: PendingJob { id: JobId(14303508), result: None } }
2026-02-24 00:36:33.810Z INFO propolis-server: LiveRepair final flush returned Ok(())
2026-02-24 00:36:33.810Z INFO propolis-server: live-repair completed successfully

Finally, we have client 1 going away:

2026-02-24 01:01:56.847Z WARN propolis-server: downstairs disconnected client = 1
2026-02-24 01:01:56.944Z WARN propolis-server: downstairs failed, too many outstanding bytes 52511744
2026-02-24 01:01:56.944Z INFO propolis-server: [1] client skip 582 in process jobs because fault

Client 1 comes back and we start Live Repair

2026-02-24 01:02:09.039Z  Downstairs client 1 starts up. (from the downstairs logs)
2026-02-24 01:02:20.371Z INFO propolis-server: downstairs client at Some([fd00:1122:3344:106::d]:19033) has region UUID 2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe client = 1
2026-02-24 01:02:20.371Z INFO propolis-server: Returning UUID:2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe matches client = 1
2026-02-24 01:02:20.636Z INFO propolis-server: client 1 is ready for live-repair

Downstairs logs now:
Our bad extent is repaired, interleaved logs here
oxz_crucible_fffddf56-10ca-4b62-9be3-5b3764a5f682 is the crucible zone

2026-02-24 01:02:44.111Z INFO crucible/14403: Move directory  "/data/regions/2b3ca602-dc02-4abb-97d-67eb2e3b2bbe/00/000/AEE.replace" to "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/AEE.completed"
2026-02-24 01:02:44.115Z INFO propolis-server: RE:2799 repair extent with ids 16396298,16396299,16396300,16396301 deps:[[JobId(16396297)]]
2026-02-24 01:02:44.116Z INFO propolis-server: got repair ok in Closing { close_job: PendingJob { id: JobId(16396298), result: None }, repair_job: PendingJob { id: JobId(16396299), result: None }, noop_job: PendingJob { id: JobId(16396300), result: None }, reopen_job: PendingJob { id: JobId(16396301), result: None } }
2026-02-24 01:02:44.116Z INFO propolis-server: Repair for extent 2799 s:2 d:[ClientId(1)]
2026-02-24 01:02:44.116Z INFO crucible/14403: Created copy dir "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/AEF.copy"
2026-02-24 01:02:44.116Z INFO crucible/14403: eid:2799 Found repair files: ["AEF"]
2026-02-24 01:02:44.518Z INFO crucible/14403: Verify extent 2799 still ready for copy
2026-02-24 01:02:44.518Z INFO crucible/14403: 1 repair files downloaded, move directory "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/AEF.copy" to "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/AEF.replace"
2026-02-24 01:02:44.519Z INFO crucible/14403: Copy files from "/data/regions/2b3ca602-dc02-4abb-97d-67eb2e3b2bbe/00/000/AEF.replace" in "/data/regions/2b3ca602-dc02-4abb-97d5 -67eb2e3b2bbe/00/000"
2026-02-24 01:02:44.638Z INFO crucible/14403: Move directory  "/data/regions/2b3ca602-dc02-4abb-97d-67eb2e3b2bbe/00/000/AEF.replace" to "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/AEF.completed"
2026-02-24 01:02:44.642Z WARN crucible/14403: 16396342 job Write waiting on 1 deps

At this point, the downstairs will have re-opened extent 2799. Because the extent should not be dirty (we close it on the other side which should result in a flush) I don't believe we actually check the hashes, we just assume it's all good and keep going.

A bunch of those "job Write waiting on 1 deps" messages, but for ever increasing job IDs
We move on and repair another extent:

2026-02-24 01:02:44.647Z WARN crucible/14403: 16396484 job Write waiting on 1 deps
2026-02-24 01:02:44.647Z WARN crucible/14403: 16396488 job Flush waiting on 23 deps
2026-02-24 01:02:44.647Z WARN crucible/14403: 16396489 job Read waiting on 1 deps
2026-02-24 01:02:44.657Z WARN crucible/14403: 16396493 job ELiveReopen waiting on 1 deps
2026-02-24 01:02:44.658Z WARN crucible/14403: 16396495 job Flush waiting on 1 deps
2026-02-24 01:02:44.664Z INFO crucible/14403: Created copy dir "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/AF0.copy"
2026-02-24 01:02:44.664Z INFO crucible/14403: eid:2800 Found repair files: ["AF0"]
2026-02-24 01:02:45.062Z INFO crucible/14403: Verify extent 2800 still ready for copy

The downstairs logs end with what appears to be the final repair message, then no more logs:

2026-02-24 01:03:02.742Z INFO crucible/14403: Created copy dir "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.copy"
2026-02-24 01:03:02.742Z INFO crucible/14403: eid:4015 Found repair files: ["FAF"]
2026-02-24 01:03:03.144Z INFO crucible/14403: Verify extent 4015 still ready for copy
2026-02-24 01:03:03.145Z INFO crucible/14403: 1 repair files downloaded, move directory "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.copy" to "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.replace"
2026-02-24 01:03:03.145Z INFO crucible/14403: Copy files from "/data/regions/2b3ca602-dc02-4abb-97d-67eb2e3b2bbe/00/000/FAF.replace" in "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000"
2026-02-24 01:03:03.249Z INFO crucible/14403: Move directory  "/data/regions/2b3ca602-dc02-4abb-97d-67eb2e3b2bbe/00/000/FAF.replace" to "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/00/000/FAF.completed"
2026-02-24 01:03:03.261Z WARN crucible/14403: 16405457 job Flush waiting on 1 deps

Propolis log showing LR completed:

2026-02-24 01:03:03.261Z INFO propolis-server: LiveRepair final flush submitted
2026-02-24 01:03:03.262Z INFO propolis-server: got repair ok in FinalFlush { flush_job: PendingJob { id: JobId(16405458), result: None } }
2026-02-24 01:03:03.262Z INFO propolis-server: LiveRepair final flush returned Ok(())
2026-02-24 01:03:03.262Z INFO propolis-server: live-repair completed successfully

Propolis logs continue, with Nexus notification of LR messages (unclear why, do we have a backlog?)

2026-02-24 01:03:03.480Z INFO propolis-server: notified Nexus of live repair progress
2026-02-24 01:03:03.487Z INFO propolis-server: notified Nexus of live repair progress

Propolis Log file ends, new file starts:

2026-02-24 01:03:04.980Z INFO propolis-server: notified Nexus of live repair progress
2026-02-24 01:03:04.989Z INFO propolis-server: notified Nexus of live repair progress

More propolis log files up through this date for the same VM, nothing other than the
flush check message comes through:

2026-02-25 20:20:22.063Z WARN propolis-server: flush check fired despite having jobs; resetting it

The last propolis log for this instance which still believes that everything is good is this one: system-illumos-propolis-server:default.log.1772054095

2026-02-25 21:14:55.386Z INFO propolis-server: request completed
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.6/src/server.rs:867
    latency_us = 2389
    local_addr = [fd00:1122:3344:102::1:1163]:55910
    method = GET
    remote_addr = [fd00:1122:3344:10a::70]:53562
    req_id = 5032d783-5a80-4319-bcb4-537a3dc5f7c7
    response_code = 200
    uri = /6cb556ac-bb82-43e1-b3d5-8dd8690f25a6

Downstairs log files:

-rw-rw-r--+  1 alan     staff    1748365 Feb 24 01:16 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771894983
-rw-rw-r--+  1 alan     staff          0 Feb 24 05:17 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771895701
-rw-rw-r--+  1 alan     staff          0 Feb 24 09:18 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771910100
-rw-rw-r--+  1 alan     staff          0 Feb 24 13:18 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771924501
-rw-rw-r--+  1 alan     staff          0 Feb 24 17:19 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771938900
-rw-rw-r--+  1 alan     staff          0 Feb 24 21:19 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771953300
-rw-rw-r--+  1 alan     staff          0 Feb 25 01:15 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771967701
-rw-rw-r--+  1 alan     staff          0 Feb 25 05:15 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771982101
-rw-rw-r--+  1 alan     staff          0 Feb 25 09:16 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1771996500
-rw-rw-r--+  1 alan     staff          0 Feb 25 13:16 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1772010900
-rw-rw-r--+  1 alan     staff          0 Feb 25 17:17 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1772025301
-rw-rw-r--+  1 alan     staff          0 Feb 25 21:18 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1772039702
-rw-rw-r--+  1 alan     staff     247722 Feb 25 21:47 oxide-crucible-downstairs:downstairs-2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe.log.1772055899

So, nothing after our repair, until it starts up and reports errors

The date on the bad extent is Feb 25th 21:38 (along with B02, B04, B03, which are okay)

-rw-r--r--   1 root     root     79708192 Feb 25 21:38 AEF

The log showing the downstairs starting up and seeing the error:

[ Feb 25 21:38:06 Enabled. ]
[ Feb 25 21:38:06 Executing start method ("/opt/oxide/lib/svc/manifest/crucible/downstairs.sh"). ]
2026-02-25 21:38:06.978Z INFO crucible: Opened existing region file "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/region.json"
2026-02-25 21:38:06.980Z INFO crucible: Database read version 1
2026-02-25 21:38:06.980Z INFO crucible: Database write version 1
Error: missing context slot for block 58607 in extent 2799
[ Feb 25 21:38:16 Stopping because service exited with an error. ]

Next propolis server starts here, and it's already too late:

File /pool/ext/e9b0a2e4-8060-41bd-a3b5-d0642246d06d/crypt/debug/oxz_propolis-server_d198d0d5-bfd4-4438-9192-27a1ae5ff0e4/system-illumos-propolis-server:default.log.1772058600
[ Feb 25 22:25:47 Enabled. ]
[ Feb 25 22:25:47 Rereading configuration. ]
[ Feb 25 22:25:48 Rereading configuration. ]

It waits for the 3rd downstairs to come online, and that never happens, so the instance never starts.
So, in summary, here are steps that lead us up to downstairs client 1 having the error in extent 2799:
(EDIT, see comments after this, I found a bit more history)

[ Feb 23 21:27:50 Enabled. ] Instance starts, downstairs running, no problems with any region or extent.
2026-02-23 22:35:49.352Z WARN propolis-server: inactivity timeout client = 0
2026-02-23 22:39:49.410Z INFO propolis-server: Repair for extent 2799 s:2 d:[ClientId(0)]

2026-02-23 22:46:41.388Z WARN propolis-server: inactivity timeout client = 0
2026-02-23 22:52:42.116Z INFO propolis-server: Repair for extent 2799 s:2 d:[ClientId(0)]

2026-02-24 00:28:54.885Z WARN propolis-server: downstairs disconnected client = 0
2026-02-24 00:29:04.887Z INFO propolis-server: Transition from Offline to Active client = 0
2026-02-24 00:29:04.887Z INFO propolis-server: [0] Replayed 418 jobs since flush: Some(JobId(13711089))

2026-02-24 00:35:33.557Z WARN propolis-server: downstairs disconnected client = 2
2026-02-24 00:36:14.984Z INFO propolis-server: Repair for extent 2799 s:1 d:[ClientId(2)]

2026-02-24 01:01:56.847Z WARN propolis-server: downstairs disconnected client = 1
2026-02-24 01:02:44.116Z INFO propolis-server: Repair for extent 2799 s:2 d:[ClientId(1)]
2026-02-25 21:14:55.386Z INFO propolis-server: request completed (final message from this VM)

2026-02-25 21:38:06.978Z INFO crucible: Opened existing region file "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/region.json" (new downstairs starts up)
[ Feb 25 21:38:16 Stopping because service exited with an error. ]

(EDIT, see comments after this, I found a bit more history)

[leftwo]

I vibe coded up a tool to compare the output from crucible-verify-raw on all extents.
Specifically, if you run crucible-verify-raw you get:

BRM13250012 # /tmp/crucible-verify-raw 004
bs:512 bytes  bc:131072  dirty:false gen:4 flush_number:37395263 ext_ver:2 bonus_sync:878 defrag:1  

So, I ran that on all extents in the region, for all three downstairs. the cvr-compare takes the output of these files and does a similar thing to crucible-downstairs dump but just uses the verify-raw output. (thes output files are in /staff/core/crucible-1906).
I'm just showing diffs here:

newexit:cvr-compare$ ./target/debug/cvr-compare BRM13250012-cvr-out.txt BRM27230045-cvr-out.txt BRM42220006-cvr-out.txt --diff                                                                                                                      
  EXT       D      GEN                FLUSH_NUMBER                 BSYNC       DEFRAG                                     
            123  1 2 3         1        2        3       1      2      3    1   2   3                                     
* 004 0004  FFF  4 4 4  37395263 37395263 37013607     878    879    875    1   1   1                                     
* A1A 2586  FFF  4 4 4  37394929 37394929 37009945    6770   6770   6562  643 643 625                                     
* A1B 2587  FFF  4 4 4  37394943 37394943 37009937    8331   8331   8092  738 738 716                                     
* A1C 2588  FFF  4 4 4  37393228 37393228 37009888    4231   4231   4067  300 300 289                                     
* AA6 2726  FFF  4 4 4  37395488 37395488 37010190   32868  32869  32679  891 891 874                                     
* AA7 2727  FFF  4 4 4  37395490 37395490 37010322   68241  68242  67897  988 988 971                 
* AA8 2728  FFF  4 4 4  37395488 37395488 37008864   19221  19222  19073  726 726 719             
* ABE 2750  FFF  4 4 4  37236873 37236873 35701178    1796   1797   1765   52  52  50             
* ABF 2751  FFF  4 4 4  37236872 37236872 35701178     974    975    960   24  24  24             
* AC0 2752  FFF  4 4 4  37269437 37269437 36997877    9736   9737   9699  298 298 297             
* AC1 2753  FFF  4 4 4  37269421 37269421 36997877   12980  12981  12862  339 339 339             
* AC2 2754  FFF  4 4 4  37394694 37394694 37011378   11751  11751  11570  646 646 632                                     
* AC3 2755  FFF  4 4 4  37394681 37394681 37011708   18695  18696  18480  752 752 731                                     
* AC4 2756  FFF  4 4 4  37394681 37394681 37009044    9141   9142   8982  370 370 361                                     
* AC6 2758  FFF  4 4 4  37394798 37394798 37009148   10461  10462  10328  756 756 748                                     
* AC7 2759  FFF  4 4 4  37394791 37394791 37013605   18991  18991  18664  650 650 643
* AC8 2760  FFF  4 4 4  37394832 37394832 37013605   14180  14181  13961  895 895 889
* AC9 2761  FFF  4 4 4  37394848 37394848 37009202   19936  19937  19638  890 890 883
* ACA 2762  FFF  4 4 4  37389743 37389743 37008029    9372   9373   9243  449 449 446
* ACC 2764  FFF  4 4 4  37336772 37336772 37013604    9076   9076   8807   64  64  64
* ACD 2765  FFF  4 4 4  37395261 37395261 37013604  108513 108513 106716  576 576 569
* ACE 2766  FFF  4 4 4  37383119 37383119 37013605   21291  21291  21088  336 336 332
* AD0 2768  FFF  4 4 4  37331151 37331151 36981868    3857   3857   3832  151 151 148
* AD1 2769  FFF  4 4 4  37395261 37395261 37013605    9961   9961   9816  253 253 251
* AD2 2770  FFF  4 4 4  37395261 37395261 36996580    1613   1613   1586  121 121 119
* ADC 2780  FFF  4 4 4  37211652 37211652 36771911    3263   3263   3261  105 105 105
* ADD 2781  FFF  4 4 4  37211652 37211652 36771911    1716   1716   1708   55  55  54
* AE2 2786  FFF  4 4 4  37394950 37394950 37009252   10954  10955  10701  547 547 539
* AE3 2787  FFF  4 4 4  37394834 37394834 37009250   17977  17977  17743  579 579 572
* AE4 2788  FFF  4 4 4  37352793 37352793 37009252    6466   6467   6391  265 265 264
* AE8 2792  FFF  4 4 4  37382027 37382027 37013604    6100   6100   5967  132 132 129
* AE9 2793  FFF  4 4 4  37395261 37395261 37013605  118088 118088 116302  962 962 947
* AEA 2794  FFF  4 4 4  37389881 37389881 37012025   13054  13054  12801  629 629 619
* AEE 2798  FFF  4 4 4  37394607 37394607 37009748   11001  11002  10766  848 848 828
* AEF 2799  FFT  4 4 4  37394626 37394626 37009787   21760  21761  21543  957 957 939
* AF0 2800  FFF  4 4 4  37392327 37392327 37008591   15372  15372  15269  508 508 502
* AF2 2802  FFF  4 4 4  37395259 37395259 37010489   12113  12113  11917  122 122 122
* AF3 2803  FFF  4 4 4  37395261 37395261 37013605  102800 102800 101225  259 259 255
* AF4 2804  FFF  4 4 4  37395261 37395261 37013602   14026  14026  13798  323 323 319
* AF8 2808  FFF  4 4 4  37395419 37395419 37009836   10790  10791  10609  645 645 629
* AF9 2809  FFF  4 4 4  37395415 37395415 37009828   39257  39257  39046  514 514 504
* AFA 2810  FFF  4 4 4  37395069 37395069 37009314   14776  14776  14595  710 710 698
* AFB 2811  FFF  4 4 4  37395067 37395067 37009305   18352  18353  18042  758 758 749
* AFC 2812  FFF  4 4 4  37395261 37395261 37013605   30656  30656  30018  848 848 835
* AFD 2813  FFF  4 4 4  37395261 37395261 37013603   48375  48375  46895  943 943 926
* AFE 2814  FFF  4 4 4  37387937 37387937 37012027    7695   7696   7573  433 433 426
* B02 2818  FFT  4 4 4  37395491 37395491 37013952   11393  11394  11213  920 920 904
* B03 2819  FFF  4 4 4  37394584 37394584 37013948   17461  17461  17131  982 982 969
* B04 2820  FFF  4 4 4  37394726 37394726 37013948   13195  13195  12958  931 931 915                                     
* B05 2821  FFF  4 4 4  37394746 37394746 37012478   17085  17086  16732  967 967 954                                     
* B06 2822  FFF  4 4 4  37389447 37389447 37012477    8456   8457   8328  422 422 415
* B08 2824  FFF  4 4 4  37395160 37395160 37009704    9675   9676   9518  620 620 609
* B09 2825  FFF  4 4 4  37395144 37395144 37009698   19072  19073  18755  686 686 677
* B0A 2826  FFF  4 4 4  37395160 37395160 37009676   15241  15241  15094  559 559 555
* B0E 2830  FFF  4 4 4  37382027 37382027 37013605   17921  17922  17589  299 299 297
* B0F 2831  FFF  4 4 4  37395261 37395261 37013605   93967  93967  92195  277 277 273
* B10 2832  FFF  4 4 4  37390928 37390928 37013601   13693  13693  13522  683 683 674
* B11 2833  FFF  4 4 4  37395261 37395261 37013605   10432  10432  10303  952 952 938
* B12 2834  FFF  4 4 4  37388683 37388683 37009631    4159   4159   4115  473 473 467
* B14 2836  FFF  4 4 4  37391675 37391675 37011043    6770   6770   6698  439 439 436
* B15 2837  FFF  4 4 4  37395261 37395261 37011032   14126  14126  13765  469 469 464
* B16 2838  FFF  4 4 4  37395261 37395261 37010910    8058   8058   7891  599 599 589

What we see suggests the data for BRM42220006 (our bad region) has many extents that have a much older flush number than the other two downstairs regions. I wonder if we missed some logs for downstairs client 1 going away that might explain why BRM42220006 appears so much older than the other two regions.

[leftwo]

Digging a bit further, I found a propolis log file from the instance that was not part of oxlog's output.
This log covers a bit more of our window right up to the VM going away.
This log is at: /staff/core/crucible-1906/BRM42220031/oxz_propolis-server_dd22643b/system-illumos-propolis-server:default.1772057989

We did an additional repair and then I see the downstairs client 1 going away and not returning. The VM continues running for 46 or so minutes before it shuts down, which explains why the flush IDs on the bad region appear to be much older than the clients 0 and 2.

Here is the new summary (copied from above and then added to)

[ Feb 23 21:27:50 Enabled. ] Instance starts, downstairs running, no problems with any region or extent.
2026-02-23 22:35:49.352Z WARN propolis-server: inactivity timeout client = 0
2026-02-23 22:39:49.410Z INFO propolis-server: Repair for extent 2799 s:2 d:[ClientId(0)]

2026-02-23 22:46:41.388Z WARN propolis-server: inactivity timeout client = 0
2026-02-23 22:52:42.116Z INFO propolis-server: Repair for extent 2799 s:2 d:[ClientId(0)]

2026-02-24 00:28:54.885Z WARN propolis-server: downstairs disconnected client = 0
2026-02-24 00:29:04.887Z INFO propolis-server: Transition from Offline to Active client = 0
2026-02-24 00:29:04.887Z INFO propolis-server: [0] Replayed 418 jobs since flush: Some(JobId(13711089))

2026-02-24 00:35:33.557Z WARN propolis-server: downstairs disconnected client = 2
2026-02-24 00:36:14.984Z INFO propolis-server: Repair for extent 2799 s:1 d:[ClientId(2)]

2026-02-24 01:01:56.847Z WARN propolis-server: downstairs disconnected client = 1
2026-02-24 01:02:44.116Z INFO propolis-server: Repair for extent 2799 s:2 d:[ClientId(1)]

2026-02-25 21:24:24.637Z WARN propolis-server: inactivity timeout client = 2
2026-02-25 21:29:30.075Z INFO propolis-server: Repair for extent 2799 s:1 d:[ClientId(2)]
2026-02-25 21:29:56.789Z INFO propolis-server: live-repair completed successfully

2026-02-25 21:32:41.702Z WARN propolis-server: inactivity timeout client = 1
2026-02-25 21:32:41.702Z WARN propolis-server: downstairs failed, too many outstanding bytes 78588928

2026-02-25 21:38:06.978Z INFO crucible: Opened existing region file "/data/regions/2b3ca602-dc02-4abb-97d5-67eb2e3b2bbe/region.json" (new downstairs starts up)
[ Feb 25 21:38:16 Stopping because service exited with an error. ]

Last VM message before it goes away shows still no contact with client 1:
2026-02-25 22:19:42.178Z INFO propolis-server: client task is exiting client = 1

Of interest here, we see that at 2026-02-25 21:29:30, client 2 extent 2799 is repaired from client 1 (which is currently bad). As part of LiveRepair, we do flush and close the extent before repairing. We don't verify that data and context slots match if we open an extent with dirty=false, so it's possible the blocks were already bad at that time, but we can't say one way or another.

We do know now that the extent on the failing region is currently dirty, which means we have done IO to some of the blocks in that extent since we did the repair from it on 2026-02-25 21:29:30, but we don't know what blocks were updated.

Both 2799 extents on the good downstairs show valid data at all blocks, and have higher flush numbers, so the extent itself has had data written to it since client 1 went away.
I'm going to look at all the blocks in all three extents and see if I can determine any clues from them.