Using existing output directory "/tmp/dsc"
start ds: 8810
start ds: 8820
start ds: 8830
start access at:127.0.0.1:9998
Starting downstairs at port 8810
Make output file at "/tmp/dsc/downstairs-8810.txt"
[8810][0] reports Starting
Starting downstairs at port 8820
Make output file at "/tmp/dsc/downstairs-8820.txt"
[8820][1] reports Starting
Starting downstairs at port 8830
Make output file at "/tmp/dsc/downstairs-8830.txt"
[8830][2] reports Starting
Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1472)
[8810][0] reports Running
Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1473)
[8830][2] reports Running
Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1474)
[8820][1] reports Running
Jan 10 18:00:19.916 INFO listening, local_addr: 127.0.0.1:9998
Control access at:127.0.0.1:9998
Jan 10 18:00:24.989 INFO accepted connection, remote_addr: 127.0.0.1:35877, local_addr: 127.0.0.1:9998
Main task has work to do, go find it
got dsc DisableRestartAll
disable restart on all: 3
Jan 10 18:00:24.990 INFO request completed, latency_us: 163, response_code: 204, uri: /disablerestart/all, method[8810] Disable keep_running
:[8830] Disable keep_running
 POST, req_id: 9b2b0aea-9e12-4204-be9a-7020d76529f0, remote_addr: 127.0.0.1:35877, local_addr: 127.0.0.1:9998
[8820] Disable keep_running
Jan 10 18:07:32.460 INFO accepted connection, remote_addr: 127.0.0.1:50368, local_addr: 127.0.0.1:9998
Main task has work to do, go find it
got dsc Shutdown
Shutdown
Jan 10 18:07:32.461Shut it down
 INFO request completed, latency_us: 79[8830] Disable keep_running
, response_code[8830] Got stop action so:false kr:false
:[8810] Disable keep_running
 [8810] Got stop action so:false kr:false
204[8820] Disable keep_running
, [8820] Got stop action so:false kr:false
uri: /shutdown, method: POST, req_id: eaabcc16-893e-4de9-8829-a2b26dbd970e, remote_addr: 127.0.0.1:50368, local_addr: 127.0.0.1:9998
[8820] Exited with: ExitStatus(unix_wait_status(9))
[8820][1] reports Exit
[8830] Exited with: ExitStatus(unix_wait_status(9))
[8830][2] reports Exit
[8810] Exited with: ExitStatus(unix_wait_status(9))
[8810][0] reports Exit
8:00:25.006396119Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477}
{"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006410646Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477}
{"msg":"Crucible c49cb738-cd2b-43c0-abc4-aa461f54078d has session id: e4b0fc04-4079-4451-9ad8-da962e2ccff7","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006421949Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Crucible runtime is spawned
Upstairs opts: Upstairs UUID: c49cb738-cd2b-43c0-abc4-aa461f54078d, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false,  cert_pem populated: false,  key_pem populated: false,  root_cert_pem populated: false,  Control: None,  read_only: false","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006506246Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Crucible stats registered with UUID: c49cb738-cd2b-43c0-abc4-aa461f54078d","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006523873Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006535384Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477}
{"msg":"c49cb738-cd2b-43c0-abc4-aa461f54078d active request set","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006655798Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006671758Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006697302Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006710697Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006722466Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006734774Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006747728Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006762296Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"io task","client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006796731Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"io task","client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006918276Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"io task","client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.006947895Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"io task","client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.007109939Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"io task","client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.007129198Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"io task","client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.00757771Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.007670117Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.007678561Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.007686131Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.007788727Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.007811176Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.008578922Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.008657543Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.008793888Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.020870832Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.020892822Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.02090683Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021045535Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021056989Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021064113Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021196938Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021206564Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[0]R flush_numbers[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021213961Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[0]R generation[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021221409Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[0]R dirty[0..12]: [false, false, false, false, false, false, false, false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021233388Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[1]R flush_numbers[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021240689Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[1]R generation[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021247714Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[1]R dirty[0..12]: [false, false, false, false, false, false, false, false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021255009Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[2]R flush_numbers[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021262052Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[2]R generation[0..12]: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021269154Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"[2]R dirty[0..12]: [false, false, false, false, false, false, false, false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.02127628Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021283546Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021290533Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021297726Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021304871Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"":"downstairs","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"No downstairs repair required","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021311883Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.02131793Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"0","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021325074Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"1","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021334747Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"client":"2","":"downstairs","session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"All required repair work is completed","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021342048Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Set Downstairs and Upstairs active after repairs","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.0213482Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"c49cb738-cd2b-43c0-abc4-aa461f54078d is now active with session: e4b0fc04-4079-4451-9ad8-da962e2ccff7","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
,"time":"2024-01-10T18:00:25.021355044Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"Set Active after no repair","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021364715Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477,"session_id":"e4b0fc04-4079-4451-9ad8-da962e2ccff7"}
{"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-01-10T18:00:25.021370989Z","hostname":"ip-10-150-1-74.us-west-2.compute.internal","pid":1477}
Region: es:16384 ec:1600 bs:4096  ts:107374182400  tb:26214400  max_io:256 or 1048576
Fill test
CLIENT: Tests done.  All submitted work has been ACK'd
----------------------------------------------------------------
 Crucible gen:1 GIO:true work queues:  Upstairs:0  downstairs:0
Downstairs last five completed: 263992 263991 263990 263989 263988
Upstairs last five completed:   262993 262992 262991 262990 262989
CLIENT: Up:0 ds:0 act:3
CLIENT: All crucible jobs finished, exiting program