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" Starting downstairs at port 8820 Make output file at "/tmp/dsc/downstairs-8820.txt" [8810][0] reports Starting Starting downstairs at port 8830 [8820][1] reports Starting Make output file at "/tmp/dsc/downstairs-8830.txt" [8830][2] reports Starting Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1483) [8810][0] reports Running Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1484) [8820][1] reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1485) [8830][2] reports Running Apr 17 17:14:48.634 INFO listening, local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 Apr 17 17:14:53.671 INFO accepted connection, remote_addr: 127.0.0.1:62886, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll disable restart on all: 3 Apr 17 17:14:53.671 INFO request completed[8810] Disable keep_running , [8820] Disable keep_running latency_us: [8830] Disable keep_running 95, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 1a4f5914-1e7e-45a1-99ed-632223b977d8, remote_addr: 127.0.0.1:62886, local_addr: 127.0.0.1:9998 Apr 17 17:18:33.479 INFO accepted connection, remote_addr: 127.0.0.1:64547, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown Apr 17 17:18:33.480 INFOShut it down request completed, latency_us: 50[8820] Disable keep_running , [8820] Got stop action so:false kr:false response_code[8830] Disable keep_running :[8830] Got stop action so:false kr:false 204, uri: /shutdown, method: POST[8810] Disable keep_running , [8810] Got stop action so:false kr:false req_id: a393f217-d522-4a7a-8106-f35721074fe9, remote_addr: 127.0.0.1:64547, local_addr: 127.0.0.1:9998 [8830] Exited with: ExitStatus(unix_wait_status(9)) [8830][2] reports Exit [8820] Exited with: ExitStatus(unix_wait_status(9)) [8820][1] reports Exit [8810] Exited with: ExitStatus(unix_wait_status(9)) [8810][0] reports Exit T17:14:53.681593615Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488} {"msg":"Upstairs <-> Downstairs Message Version: 6","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681599424Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488} {"msg":"Crucible 3ad7ca4c-2d4c-49a1-81a6-216f0ba4d918 has session id: 2c347d7f-7ea4-4a95-83d8-a2efad243299","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681603414Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Upstairs opts: Upstairs UUID: 3ad7ca4c-2d4c-49a1-81a6-216f0ba4d918, 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-04-17T17:14:53.681611373Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Crucible stats registered with UUID: 3ad7ca4c-2d4c-49a1-81a6-216f0ba4d918","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681615663Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681619423Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488} {"msg":"3ad7ca4c-2d4c-49a1-81a6-216f0ba4d918 active request set","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681686827Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681692897Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681703476Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681708226Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681712496Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681716605Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681720685Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.6817771Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"io task","client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.68178356Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"io task","client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.68178825Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"io task","client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_connection connected from Ok(127.0.0.1:52543)","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681920579Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"io task","client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_connection connected from Ok(127.0.0.1:35133)","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681934158Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"io task","client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_connection connected from Ok(127.0.0.1:56150)","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.681941887Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"io task","client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.68228954Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.682298319Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.682304329Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.682308758Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.682323497Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.682330976Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.682555429Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.682564328Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.682568797Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.688812922Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.688824861Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.688830801Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.690908896Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.690922225Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.690929245Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.690953093Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.690958692Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.690963052Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.690967472Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.690971871Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.690978811Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.690983101Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.6909876Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.69099228Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.690996599Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"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-04-17T17:14:53.691000759Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691004899Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691009048Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691013208Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691017358Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"":"downstairs","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691021537Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691025167Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"0","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691029347Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"1","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691033406Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"client":"2","":"downstairs","session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691037516Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691042616Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"3ad7ca4c-2d4c-49a1-81a6-216f0ba4d918 is now active with session: 2c347d7f-7ea4-4a95-83d8-a2efad243299","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691046335Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691049985Z","hostname":"Wait for a query_work_queue command to finish before sending IO w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488,"session_id":"2c347d7f-7ea4-4a95-83d8-a2efad243299"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-04-17T17:14:53.691057595Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488} 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: 103836 103835 103834 103833 103832 Upstairs last five completed: 102837 102836 102835 102834 102833 CLIENT: Up:0 ds:0 act:3 CLIENT: All crucible jobs finished, exiting program {"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2024-04-17T17:18:32.714351781Z","hostname":"w-01HVPGMX7AQ2SS5SAZAXTX27D0","pid":1488}