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" Starting downstairs at port 8830 Make output file at "/tmp/dsc/downstairs-8830.txt" [8810][0] reports Starting [8820][1] reports Starting [8830][2] reports Starting Downstairs /var/tmp/dsc/8810 port 8810 PID:Some(1454) [8810][0] reports Running Downstairs /var/tmp/dsc/8830 port 8830 PID:Some(1455) [8830][2] reports Running Downstairs /var/tmp/dsc/8820 port 8820 PID:Some(1456) Feb 28 22:14:27.475 INFO listening[8820][1] reports Running , local_addr: 127.0.0.1:9998 Control access at:127.0.0.1:9998 Feb 28 22:14:32.514 INFO accepted connection, remote_addr: 127.0.0.1:51631, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc DisableRestartAll disable restart on all: 3 Feb 28 22:14:32.515 INFO request completed, latency_us: 118, response_code: 204, uri: /disablerestart/all, method: POST, req_id: 8fc40bd4-ea72-4c8a-b1d1-7b1ed2f5ed84, [8820] Disable keep_running remote_addr: 127.0.0.1:51631, local_addr: 127.0.0.1:9998 [8810] Disable keep_running [8830] Disable keep_running Feb 28 22:19:48.529 INFO accepted connection, remote_addr: 127.0.0.1:33028, local_addr: 127.0.0.1:9998 Main task has work to do, go find it got dsc Shutdown Shutdown [8810] Disable keep_running Shut it down Feb 28 22:19:48.530[8810] Got stop action so:false kr:false [8830] Disable keep_running INFO request completed, latency_us: 57, response_code: 204, uri: /shutdown, method: POST, req_id:[8830] Got stop action so:false kr:false [8820] Disable keep_running 399fb4c4-f3d3-4082-a1bb-1007d3fef8e8[8820] Got stop action so:false kr:false , remote_addr: 127.0.0.1:33028, 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 ":"2024-02-28T22:14:32.527168486Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459} {"msg":"Upstairs <-> Downstairs Message Version: 5","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527174846Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459} {"msg":"Crucible 29eac91c-69d6-4264-8d51-79e198016cd4 has session id: 48f71347-e3cb-4ae5-9142-74e9151fabec","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527179056Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Upstairs opts: Upstairs UUID: 29eac91c-69d6-4264-8d51-79e198016cd4, 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-02-28T22:14:32.527188225Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Crucible stats registered with UUID: 29eac91c-69d6-4264-8d51-79e198016cd4","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527192405Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"The guest has requested activation with gen:1","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527196225Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459} {"msg":"29eac91c-69d6-4264-8d51-79e198016cd4 active request set","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527199904Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527203764Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527214083Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527218953Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527223303Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527227572Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"client set_active_request while in New; waiting...","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527231812Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527288139Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"io task","client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527296428Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"io task","client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527301218Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"io task","client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527402361Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"io task","client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.52741473Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"io task","client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_connection connected","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527494595Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"io task","client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527704981Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"[0] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.52771831Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527769017Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"[1] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527778906Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527790585Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"[2] Transition from New to WaitActive","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.527798085Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.527972683Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.527986322Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.528071757Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.534920695Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"[1] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.534934064Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.534940844Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.53499468Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"[0] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.53500129Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Waiting for true more clients to be ready","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535005939Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"ds_transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535009909Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"[2] Transition from WaitActive to WaitQuorum","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535014319Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535028738Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535033188Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535041237Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535045807Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535050187Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535054576Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535058876Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535063156Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"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-02-28T22:14:32.535067475Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Max found gen is 1","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535071795Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Generation requested: 1 >= found:1","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535076135Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Next flush: 1","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535080515Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535084834Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"":"downstairs","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535089294Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535093144Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"0","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535097464Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"1","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535103383Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"client":"2","":"downstairs","session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"All required reconciliation work is completed","v":0,"name":"crucible"Wait for a query_work_queue command to finish before sending IO ,"level":30,"time":"2024-02-28T22:14:32.535110893Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535114942Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"29eac91c-69d6-4264-8d51-79e198016cd4 is now active with session: 48f71347-e3cb-4ae5-9142-74e9151fabec","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535118822Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535122602Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459,"session_id":"48f71347-e3cb-4ae5-9142-74e9151fabec"} {"msg":"The guest has finished waiting for activation with:1","v":0,"name":"crucible","level":30,"time":"2024-02-28T22:14:32.535126362Z","hostname":"ip-10-150-1-76.us-west-2.compute.internal","pid":1459} 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:7 States: Active Active Active GW_ID ACK DSID TYPE BLOCKS DS:0 DS:1 DS:2 REPLAY 262760 Acked 263759 Write 100 Done Done Done false 262761 Acked 263760 Write 100 Done Done Done false 262762 Acked 263761 Write 100 Done Done Done false 262763 Acked 263762 Write 100 Done Done Done false 262764 Acked 263763 Write 100 Done Done Done false 262765 Acked 263764 Write 100 Done Done Done false 262766 Acked 263765 Flush 0 Done Done Sent false STATES DS:0 DS:1 DS:2 TOTAL New 0 0 0 0 Sent 0 0 1 1 Done 7 7 6 20 Skipped 0 0 0 0 Error 0 0 0 0 Last Flush: 263765 263765 263758 Downstairs last five completed: 263758 263757 263756 263755 263754 Upstairs last five completed: 262766 262759 262765 262764 262763 CLIENT: Up:0 ds:7 act:3 ---------------------------------------------------------------- Crucible gen:1 GIO:true work queues: Upstairs:0 downstairs:0 Downstairs last five completed: 263765 263764 263763 263762 263761 Upstairs last five completed: 262766 262759 262765 262764 262763 CLIENT: Up:0 ds:0 act:3 CLIENT: All crucible jobs finished, exiting program