From e8fc7df3c58df7862ad011cddec1db540ba0f956 Mon Sep 17 00:00:00 2001 From: Tiago Castro Date: Thu, 19 Dec 2024 22:07:43 +0000 Subject: [PATCH] ci: switch from jenkins to github actions Jenkins has become troublesome to maintain and makes it harder for users to see and test output without adding new users. We could probably spend some time improving that, but the current Jenkins is also setup on systems managed by the sponsoring company so it makes sense to move away from that at least. In order to run the CI tests we need a relatively powerful CI system so we are making use of the ubuntu-latest-16-cores runners. The tests seem to run slower than on Jenkins. Part of it may be explained because the dependencies are not pre-cache and also the pre-requisites which take time to install. Signed-off-by: Tiago Castro --- .github/auto_assign.yml | 1 - .github/workflows/bdd.yml | 68 + .github/workflows/image-pr.yml | 20 + .github/workflows/image.yml | 30 + .github/workflows/lint.yml | 31 + .github/workflows/nightly-ci.yml | 15 + .github/workflows/pr-ci.yml | 28 + .github/workflows/unit-int.yml | 51 + .gitignore | 1 + .../src/bin/core/tests/controller/mod.rs | 1 + docker-logs.txt | 1478 +++++++++++++++++ scripts/python/test.sh | 2 + shell.nix | 4 +- tests/bdd/common/deployer.py | 3 + tests/bdd/common/docker.py | 21 + ...est_cordon_node.py => test_cordon-node.py} | 0 .../readiness-probe.feature} | 0 .../test_readiness-probe.py} | 9 +- .../__init__.py | 0 .../garbage-collection.feature} | 0 .../test_garbage-collection.py} | 4 +- .../create/create.feature | 0 .../create/test_create.py | 0 .../publish/feature.feature | 0 .../publish/test_publish.py | 0 .../set-replica}/feature.feature | 0 .../set-replica/test_set-replica.py} | 0 ...node_topology.py => test_node-topology.py} | 62 +- ...pool_topology.py => test_pool-topology.py} | 39 +- 29 files changed, 1813 insertions(+), 55 deletions(-) create mode 100644 .github/workflows/bdd.yml create mode 100644 .github/workflows/image-pr.yml create mode 100644 .github/workflows/image.yml create mode 100644 .github/workflows/lint.yml create mode 100644 .github/workflows/nightly-ci.yml create mode 100644 .github/workflows/pr-ci.yml create mode 100644 .github/workflows/unit-int.yml create mode 100644 docker-logs.txt rename tests/bdd/features/cordon/node/{test_cordon_node.py => test_cordon-node.py} (100%) rename tests/bdd/features/{health_probes/readiness_probe.feature => health-probes/readiness-probe.feature} (100%) rename tests/bdd/features/{health_probes/test_readiness_probe.py => health-probes/test_readiness-probe.py} (96%) rename tests/bdd/features/snapshot/{garbage_collection => garbage-collection}/__init__.py (100%) rename tests/bdd/features/snapshot/{garbage_collection/garbage_collection.feature => garbage-collection/garbage-collection.feature} (100%) rename tests/bdd/features/snapshot/{garbage_collection/test_garbage_collection.py => garbage-collection/test_garbage-collection.py} (98%) rename tests/bdd/features/{volume_group => volume-group}/create/create.feature (100%) rename tests/bdd/features/{volume_group => volume-group}/create/test_create.py (100%) rename tests/bdd/features/{volume_group => volume-group}/publish/feature.feature (100%) rename tests/bdd/features/{volume_group => volume-group}/publish/test_publish.py (100%) rename tests/bdd/features/{volume_group/set_replica => volume-group/set-replica}/feature.feature (100%) rename tests/bdd/features/{volume_group/set_replica/test_set_replica.py => volume-group/set-replica/test_set-replica.py} (100%) rename tests/bdd/features/volume/topology/{test_node_topology.py => test_node-topology.py} (94%) rename tests/bdd/features/volume/topology/{test_pool_topology.py => test_pool-topology.py} (95%) diff --git a/.github/auto_assign.yml b/.github/auto_assign.yml index e38ca7030..f8f3cfce8 100644 --- a/.github/auto_assign.yml +++ b/.github/auto_assign.yml @@ -8,7 +8,6 @@ addAssignees: false reviewers: - tiagolobocastro - Abhinandan-Purkait - - chriswldenyer # A list of keywords to be skipped the process that add reviewers if pull requests include it skipKeywords: diff --git a/.github/workflows/bdd.yml b/.github/workflows/bdd.yml new file mode 100644 index 000000000..fe90d2c1b --- /dev/null +++ b/.github/workflows/bdd.yml @@ -0,0 +1,68 @@ +name: BDD CI +on: + workflow_call: + # push: + # branches: + # - ci + +env: + CARGO_TERM_COLOR: always + CARGO_INCREMENTAL: 0 + CI: 1 + +jobs: + bdd-tests: + runs-on: ubuntu-latest-16-cores + steps: + - uses: actions/checkout@v4 + with: + fetch-depth: 0 + submodules: 'recursive' + - uses: DeterminateSystems/nix-installer-action@v14 + - uses: DeterminateSystems/magic-nix-cache-action@v8 + - name: Pre-populate nix-shell + run: | + export NIX_PATH=nixpkgs=$(jq '.nixpkgs.url' nix/sources.json -r) + echo "NIX_PATH=$NIX_PATH" >> $GITHUB_ENV + nix-shell --run "echo" shell.nix + - name: Handle Rust dependencies caching + uses: Swatinem/rust-cache@v2 + - name: Build binaries + run: nix-shell --run "cargo build --bins" + - name: Setup Test Pre-Requisites + run: | + sudo sysctl -w vm.nr_hugepages=3072 + sudo apt-get install linux-modules-extra-$(uname -r) + sudo modprobe nvme_tcp + echo "never" | sudo tee /sys/kernel/mm/transparent_hugepage/enabled + - name: Run BDD Tests + run: | + nix-shell --run "deployer start --image-pull-policy always -w 60s && deployer stop" + # while [ $? -eq 0 ]; do + # nix-shell --run "./scripts/python/test.sh -x" + # done + nix-shell --run "./scripts/python/test.sh" + - uses: actions/upload-artifact@v4 + if: failure() + with: + name: failed-docker-logs + path: docker-logs.txt + - name: Cleanup + if: always() + run: | + nix-shell --run "./scripts/python/test-residue-cleanup.sh" + cat /proc/meminfo | grep -i huge + - name: Surface failing tests + if: always() + uses: pmeier/pytest-results-action@main + with: + path: report.xml + summary: true + display-options: a + fail-on-empty: true + title: Test results +# debugging + # - name: Setup tmate session + # if: ${{ failure() }} + # timeout-minutes: 240 + # uses: mxschmitt/action-tmate@v3 diff --git a/.github/workflows/image-pr.yml b/.github/workflows/image-pr.yml new file mode 100644 index 000000000..bddd281f7 --- /dev/null +++ b/.github/workflows/image-pr.yml @@ -0,0 +1,20 @@ +name: ImageBuild CI +on: + workflow_call: + +env: + CARGO_TERM_COLOR: always + CARGO_INCREMENTAL: 0 + CI: 1 + +jobs: + image-build-test: + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@v4 + with: + submodules: 'recursive' + - uses: DeterminateSystems/nix-installer-action@v14 + - uses: DeterminateSystems/magic-nix-cache-action@v8 + - name: Test building the release images + run: ./scripts/release.sh --skip-publish --build-bins diff --git a/.github/workflows/image.yml b/.github/workflows/image.yml new file mode 100644 index 000000000..f71b104cc --- /dev/null +++ b/.github/workflows/image.yml @@ -0,0 +1,30 @@ +name: Image Push +on: + push: + branches: + - develop + - 'release/**' + tags: + - 'v[0-9]+.[0-9]+.[0-9]+**' + +env: + CARGO_TERM_COLOR: always + CARGO_INCREMENTAL: 0 + CI: 1 + +jobs: + image-build-test: + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@v4 + with: + submodules: 'recursive' + - uses: DeterminateSystems/nix-installer-action@v14 + - uses: DeterminateSystems/magic-nix-cache-action@v8 + - name: Login to Docker Hub + uses: docker/login-action@v3 + with: + username: ${{ secrets.DOCKERHUB_USERNAME }} + password: ${{ secrets.DOCKERHUB_TOKEN }} + - name: Build and push the release images + run: ./scripts/release.sh diff --git a/.github/workflows/lint.yml b/.github/workflows/lint.yml new file mode 100644 index 000000000..b2bca9cd8 --- /dev/null +++ b/.github/workflows/lint.yml @@ -0,0 +1,31 @@ +name: Linter CI +on: + workflow_call: + +env: + CARGO_TERM_COLOR: always + CARGO_INCREMENTAL: 0 + CI: 1 + +jobs: + linter: + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@v4 + with: + submodules: 'recursive' + - uses: DeterminateSystems/nix-installer-action@v14 + - uses: DeterminateSystems/magic-nix-cache-action@v8 + - name: Pre-populate nix-shell + run: | + export NIX_PATH=nixpkgs=$(jq '.nixpkgs.url' nix/sources.json -r) + echo "NIX_PATH=$NIX_PATH" >> $GITHUB_ENV + nix-shell --run "echo" shell.nix + - name: Handle Rust dependencies caching + uses: Swatinem/rust-cache@v2 + - name: Lint rust code + run: nix-shell --run "./scripts/rust/linter.sh" + - name: Lint python code + run: nix-shell --run "black --diff --check tests/bdd/" + - name: Lint nix code + run: nix-shell --run "nixpkgs-fmt --check ." diff --git a/.github/workflows/nightly-ci.yml b/.github/workflows/nightly-ci.yml new file mode 100644 index 000000000..396ff3e41 --- /dev/null +++ b/.github/workflows/nightly-ci.yml @@ -0,0 +1,15 @@ +name: Nightly CI +on: + workflow_dispatch: + +jobs: + ci: + uses: ./.github/workflows/pr-ci.yml + nightly-ci: + if: ${{ success() }} + needs: + - ci + runs-on: ubuntu-latest + steps: + - name: CI succeeded + run: exit 0 diff --git a/.github/workflows/pr-ci.yml b/.github/workflows/pr-ci.yml new file mode 100644 index 000000000..6fb3dcb6d --- /dev/null +++ b/.github/workflows/pr-ci.yml @@ -0,0 +1,28 @@ +name: Bors CI +on: + workflow_call: + push: + branches: + - staging + - trying + +jobs: + lint-ci: + uses: ./.github/workflows/lint.yml + int-ci: + uses: ./.github/workflows/unit-int.yml + bdd-ci: + uses: ./.github/workflows/bdd.yml + image-ci: + uses: ./.github/workflows/image-pr.yml + bors-ci: + if: ${{ success() }} + needs: + - lint-ci + - int-ci + - bdd-ci + - image-ci + runs-on: ubuntu-latest + steps: + - name: CI succeeded + run: exit 0 diff --git a/.github/workflows/unit-int.yml b/.github/workflows/unit-int.yml new file mode 100644 index 000000000..2173d6542 --- /dev/null +++ b/.github/workflows/unit-int.yml @@ -0,0 +1,51 @@ +name: Integration CI +on: + workflow_call: + +env: + CARGO_TERM_COLOR: always + CARGO_INCREMENTAL: 0 + CI: 1 + +jobs: + int-tests: + runs-on: ubuntu-latest-16-cores + steps: + - uses: actions/checkout@v4 + with: + fetch-depth: 0 + submodules: 'recursive' + - uses: DeterminateSystems/nix-installer-action@v14 + - uses: DeterminateSystems/magic-nix-cache-action@v8 + - name: Pre-populate nix-shell + run: | + export NIX_PATH=nixpkgs=$(jq '.nixpkgs.url' nix/sources.json -r) + echo "NIX_PATH=$NIX_PATH" >> $GITHUB_ENV + nix-shell --run "echo" shell.nix + - name: Handle Rust dependencies caching + uses: Swatinem/rust-cache@v2 + with: + save-if: ${{ startsWith(github.ref_name, 'release/') || github.ref_name == 'develop' }} + - name: Build rust binaries + run: nix-shell --run "cargo build --bins" + - name: Build the tests + run: nix-shell --run "./scripts/rust/test.sh --no-run" + - name: Setup Test Pre-Requisites + run: | + sudo sysctl -w vm.nr_hugepages=2560 + sudo apt-get install linux-modules-extra-$(uname -r) + sudo modprobe nvme_tcp + - name: Run Tests + run: | + # pre-pull the required container images + deployer start --image-pull-policy always -w 60s && deployer stop + # includes both unit and integration tests + nix-shell --run "./scripts/rust/test.sh" + - name: Cleanup + if: always() + run: nix-shell --run "./scripts/rust/deployer-cleanup.sh" +# debugging + # - name: Setup tmate session + # if: ${{ failure() }} + # timeout-minutes: 120 + # uses: mxschmitt/action-tmate@v3 diff --git a/.gitignore b/.gitignore index 449a020dc..afbd7276b 100644 --- a/.gitignore +++ b/.gitignore @@ -26,4 +26,5 @@ __pycache__ /rpc/mayastor-api /local-fio-0-verify.state /report.xml +/docker-logs.txt /.tmp diff --git a/control-plane/agents/src/bin/core/tests/controller/mod.rs b/control-plane/agents/src/bin/core/tests/controller/mod.rs index 9c825aec0..4aec75dc4 100644 --- a/control-plane/agents/src/bin/core/tests/controller/mod.rs +++ b/control-plane/agents/src/bin/core/tests/controller/mod.rs @@ -81,6 +81,7 @@ async fn store_lease_lock() { .await .unwrap(); + tokio::time::sleep(std::time::Duration::from_secs(1)).await; let lease_ttl = std::time::Duration::from_secs(2); let _core_agent = Etcd::new_leased( ["0.0.0.0:2379"], diff --git a/docker-logs.txt b/docker-logs.txt new file mode 100644 index 000000000..3736c955e --- /dev/null +++ b/docker-logs.txt @@ -0,0 +1,1478 @@ +2025-01-02 16:15:20.389430: Logs for Test tests/bdd/features/volume/topology/test_node_topology.py::test_suitable_nodes_which_contain_volume_spread_topology_key[True-zone-us-1-<=-succeed-must be-zone-us=us-west-1,zone-us=different-value] (call): +---------------------------------------- + +Logs for container jaeger: +---------------------------------------- +2025/01/02 16:15:18 maxprocs: Leaving GOMAXPROCS=16: CPU quota undefined +2025/01/02 16:15:18 application version: git-commit=65cff3c30823ea20d3dc48bae39d5685ae307da5, git-version=v1.64.0, build-date=2024-12-06T21:17:15Z +{"level":"info","ts":1735834518.5963836,"caller":"flags/service.go:99","msg":"Mounting metrics handler on admin server","route":"/metrics"} +{"level":"info","ts":1735834518.5964174,"caller":"flags/service.go:105","msg":"Mounting expvar handler on admin server","route":"/debug/vars"} +{"level":"info","ts":1735834518.596628,"caller":"flags/admin.go:119","msg":"Mounting health check on admin server","route":"/"} +{"level":"info","ts":1735834518.596789,"caller":"flags/admin.go:133","msg":"Starting admin HTTP server","http-addr":":14269"} +{"level":"info","ts":1735834518.5970204,"caller":"flags/admin.go:111","msg":"Admin server started","http.host-port":"[::]:14269","health-status":"unavailable"} +{"level":"info","ts":1735834518.5970962,"caller":"grpc@v1.68.1/clientconn.go:162","msg":"[core] original dial target is: \"localhost:4317\""} +{"level":"info","ts":1735834518.5971262,"caller":"grpc@v1.68.1/clientconn.go:440","msg":"[core] [Channel #1]Channel created"} +{"level":"info","ts":1735834518.597145,"caller":"grpc@v1.68.1/clientconn.go:193","msg":"[core] [Channel #1]parsed dial target is: resolver.Target{URL:url.URL{Scheme:\"dns\", Opaque:\"\", User:(*url.Userinfo)(nil), Host:\"\", Path:\"/localhost:4317\", RawPath:\"\", OmitHost:false, ForceQuery:false, RawQuery:\"\", Fragment:\"\", RawFragment:\"\"}}"} +{"level":"info","ts":1735834518.5971525,"caller":"grpc@v1.68.1/clientconn.go:194","msg":"[core] [Channel #1]Channel authority set to \"localhost:4317\""} +{"level":"info","ts":1735834518.5972655,"caller":"memory/factory.go:77","msg":"Memory storage initialized","configuration":{"MaxTraces":0}} +{"level":"info","ts":1735834518.597451,"caller":"static/provider.go:149","msg":"Loading sampling strategies","filename":"/etc/jaeger/sampling_strategies.json"} +{"level":"warn","ts":1735834518.5975316,"caller":"static/provider.go:71","msg":"Default operations level strategies will not be included for Ratelimiting service strategies.This behavior will be changed in future releases. Cf. https://github.com/jaegertracing/jaeger/issues/5270"} +{"level":"info","ts":1735834518.6007235,"caller":"grpc@v1.68.1/server.go:684","msg":"[core] [Server #2]Server created"} +{"level":"info","ts":1735834518.6007981,"caller":"server/grpc.go:93","msg":"Starting jaeger-collector gRPC server","grpc.host-port":"[::]:14250"} +{"level":"info","ts":1735834518.6008089,"caller":"server/http.go:45","msg":"Starting jaeger-collector HTTP server","http host-port":":14268"} +{"level":"info","ts":1735834518.6011357,"caller":"app/collector.go:139","msg":"Not listening for Zipkin HTTP traffic, port not configured"} +{"level":"info","ts":1735834518.6011271,"caller":"grpc@v1.68.1/server.go:880","msg":"[core] [Server #2 ListenSocket #3]ListenSocket created"} +{"level":"info","ts":1735834518.6012454,"caller":"handler/otlp_receiver.go:69","msg":"OTLP receiver status change","status":"StatusStarting"} +{"level":"warn","ts":1735834518.6013618,"caller":"internal@v0.115.0/warning.go:40","msg":"Using the 0.0.0.0 address exposes this server to every network interface, which may facilitate Denial of Service attacks.","documentation":"https://github.com/open-telemetry/opentelemetry-collector/blob/main/docs/security-best-practices.md#safeguards-against-denial-of-service-attacks"} +{"level":"info","ts":1735834518.6013913,"caller":"grpc@v1.68.1/server.go:684","msg":"[core] [Server #4]Server created"} +{"level":"info","ts":1735834518.6014004,"caller":"otlpreceiver@v0.115.0/otlp.go:112","msg":"Starting GRPC server","endpoint":":4317"} +{"level":"warn","ts":1735834518.601435,"caller":"internal@v0.115.0/warning.go:40","msg":"Using the 0.0.0.0 address exposes this server to every network interface, which may facilitate Denial of Service attacks.","documentation":"https://github.com/open-telemetry/opentelemetry-collector/blob/main/docs/security-best-practices.md#safeguards-against-denial-of-service-attacks"} +{"level":"info","ts":1735834518.6014485,"caller":"otlpreceiver@v0.115.0/otlp.go:169","msg":"Starting HTTP server","endpoint":":4318"} +{"level":"info","ts":1735834518.6014924,"caller":"grpc@v1.68.1/server.go:880","msg":"[core] [Server #4 ListenSocket #5]ListenSocket created"} +{"level":"warn","ts":1735834518.6015613,"caller":"internal@v0.115.0/warning.go:40","msg":"Using the 0.0.0.0 address exposes this server to every network interface, which may facilitate Denial of Service attacks.","documentation":"https://github.com/open-telemetry/opentelemetry-collector/blob/main/docs/security-best-practices.md#safeguards-against-denial-of-service-attacks"} +{"level":"info","ts":1735834518.6015775,"caller":"grpc@v1.68.1/server.go:684","msg":"[core] [Server #6]Server created"} +{"level":"info","ts":1735834518.6018648,"caller":"app/static_handler.go:92","msg":"Using UI configuration","path":""} +{"level":"warn","ts":1735834518.601896,"caller":"internal@v0.115.0/warning.go:40","msg":"Using the 0.0.0.0 address exposes this server to every network interface, which may facilitate Denial of Service attacks.","documentation":"https://github.com/open-telemetry/opentelemetry-collector/blob/main/docs/security-best-practices.md#safeguards-against-denial-of-service-attacks"} +{"level":"info","ts":1735834518.6019235,"caller":"app/server.go:254","msg":"Query server started","http_addr":"[::]:16686","grpc_addr":"[::]:16685"} +{"level":"info","ts":1735834518.6019328,"caller":"healthcheck/handler.go:118","msg":"Health Check state change","status":"ready"} +{"level":"info","ts":1735834518.601941,"caller":"app/server.go:334","msg":"Starting GRPC server","port":16685,"addr":":16685"} +{"level":"info","ts":1735834518.601958,"caller":"grpc@v1.68.1/server.go:880","msg":"[core] [Server #6 ListenSocket #7]ListenSocket created"} +{"level":"info","ts":1735834518.6019664,"caller":"app/server.go:320","msg":"Starting HTTP server","port":16686,"addr":":16686"} + + +Logs for container io-engine-3: +---------------------------------------- +[2025-01-02T16:15:19.317805348+00:00 INFO io_engine:io-engine.rs:253] Engine responsible for managing I/Os version 1.0.0, revision 17488f4a7da3 (v1.0.0+997) +[2025-01-02T16:15:19.317896380+00:00 INFO io_engine:io-engine.rs:232] free_pages 2MB: 4096 nr_pages 2MB: 4096 +[2025-01-02T16:15:19.317900160+00:00 INFO io_engine:io-engine.rs:233] free_pages 1GB: 0 nr_pages 1GB: 0 +[2025-01-02T16:15:19.317964611+00:00 INFO io_engine:io-engine.rs:284] kernel io_uring support: yes +[2025-01-02T16:15:19.317968731+00:00 INFO io_engine:io-engine.rs:288] kernel nvme initiator multipath support: yes +[2025-01-02T16:15:19.317993612+00:00 INFO io_engine::subsys::config:mod.rs:233] Applying Mayastor configuration settings +[2025-01-02T16:15:19.317996702+00:00 DEBUG io_engine::subsys::config::opts:opts.rs:390] spdk_bdev_nvme_opts { action_on_timeout: 4, timeout_us: 5000000, timeout_admin_us: 5000000, keep_alive_timeout_ms: 10000, transport_retry_count: 0, arbitration_burst: 0, low_priority_weight: 0, medium_priority_weight: 0, high_priority_weight: 0, nvme_adminq_poll_period_us: 1000, nvme_ioq_poll_period_us: 0, io_queue_requests: 0, delay_cmd_submit: true, bdev_retry_count: 0, transport_ack_timeout: 0, ctrlr_loss_timeout_sec: 0, reconnect_delay_sec: 0, fast_io_fail_timeout_sec: 0, disable_auto_failback: false, generate_uuids: true, transport_tos: 0, nvme_error_stat: false, rdma_srq_size: 0, io_path_stat: false, allow_accel_sequence: false, rdma_max_cq_size: 0, rdma_cm_event_timeout_ms: 0, dhchap_digests: 0, dhchap_dhgroups: 0 } +[2025-01-02T16:15:19.318007252+00:00 INFO io_engine::subsys::config::opts:opts.rs:395] NVMe Bdev options successfully applied +[2025-01-02T16:15:19.318009322+00:00 INFO io_engine::subsys::config::opts:opts.rs:538] Bdev options successfully applied +[2025-01-02T16:15:19.318011702+00:00 INFO io_engine::subsys::config::opts:opts.rs:694] Socket options successfully applied +[2025-01-02T16:15:19.318013612+00:00 INFO io_engine::subsys::config::opts:opts.rs:733] I/O buffer options successfully applied +[2025-01-02T16:15:19.318015312+00:00 INFO io_engine::subsys::config:mod.rs:239] Config { + source: None, + nvmf_tgt_conf: NvmfTgtConfig { + name: "mayastor_target", + max_namespaces: 2048, + crdt: [ + 0, + 0, + 0, + ], + opts_tcp: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 131072, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 0, + }, + interface: None, + rdma: None, + opts_rdma: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 8192, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 4095, + }, + }, + nvme_bdev_opts: NvmeBdevOpts { + action_on_timeout: 4, + timeout_us: 5000000, + timeout_admin_us: 5000000, + keep_alive_timeout_ms: 10000, + transport_retry_count: 0, + arbitration_burst: 0, + low_priority_weight: 0, + medium_priority_weight: 0, + high_priority_weight: 0, + nvme_adminq_poll_period_us: 1000, + nvme_ioq_poll_period_us: 0, + io_queue_requests: 0, + delay_cmd_submit: true, + bdev_retry_count: 0, + transport_ack_timeout: 0, + ctrlr_loss_timeout_sec: 0, + reconnect_delay_sec: 0, + fast_io_fail_timeout_sec: 0, + disable_auto_failback: false, + generate_uuids: true, + }, + bdev_opts: BdevOpts { + bdev_io_pool_size: 65535, + bdev_io_cache_size: 512, + iobuf_small_cache_size: 128, + iobuf_large_cache_size: 16, + }, + nexus_opts: NexusOpts { + nvmf_enable: true, + nvmf_discovery_enable: true, + nvmf_nexus_port: 4421, + nvmf_replica_port: 8420, + }, + socket_opts: PosixSocketOpts { + recv_buf_size: 2097152, + send_buf_size: 2097152, + enable_recv_pipe: true, + enable_zero_copy_send: true, + enable_quickack: true, + enable_placement_id: 0, + enable_zerocopy_send_server: true, + enable_zerocopy_send_client: false, + zerocopy_threshold: 0, + }, + iobuf_opts: IoBufOpts { + small_pool_count: 8192, + large_pool_count: 2048, + small_bufsize: 8192, + large_bufsize: 135168, + }, + eal_opts: EalOpts { + reactor_mask: None, + core_list: None, + developer_delay: None, + }, +} +[2025-01-02T16:15:19.318092724+00:00 DEBUG io_engine::core::env:env.rs:750] EAL arguments ["mayastor", "--no-shconf", "-m 0", "--base-virtaddr=0x200000000000", "--file-prefix=mayastor_pid1", "--huge-unlink", "--log-level=lib.eal:6", "--log-level=lib.cryptodev:5", "--log-level=user1:6", "--match-allocations", "-l 2"] +TELEMETRY: No legacy callbacks, legacy socket not created +[2025-01-02T16:15:19.435903169+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'bdev_io_ctx' with 65535 elements (24 bytes size) successfully created +[2025-01-02T16:15:19.438244927+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'nvme_ctrl_io_ctx' with 65535 elements (72 bytes size) successfully created +[2025-01-02T16:15:19.438265307+00:00 INFO io_engine::core::env:env.rs:1015] Total number of cores available: 1 +[2025-01-02T16:15:19.449929032+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'init_thread' (0x55a12466f690) on core #2 +[2025-01-02T16:15:19.449946953+00:00 INFO io_engine::core::reactor:reactor.rs:156] Init thread ID 1 +[2025-01-02T16:15:19.449949933+00:00 INFO io_engine::core::env:env.rs:1050] All cores locked and loaded! +[2025-01-02T16:15:19.449977493+00:00 DEBUG io_engine::subsys::config:mod.rs:51] mayastor subsystem init +TELEMETRY: Socket write base info to client failed +TELEMETRY: Socket write base info to client failed +TELEMETRY: Socket write base info to client failed +[2025-01-02T16:15:19.585815122+00:00 INFO io_engine::bdev::nexus::nexus_module:nexus_module.rs:36] Initializing Nexus CAS Module +[2025-01-02T16:15:19.585838643+00:00 DEBUG io_engine::subsys::nvmf:mod.rs:85] NVMF subsystem init +[2025-01-02T16:15:19.585858503+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'mayastor_nvmf_tcp_pg_core_2' (0x55a1246c3310) on core #2 +[2025-01-02T16:15:19.585913224+00:00 DEBUG mayastor::spdk:tcp.c:672] *** TCP Transport Init *** +[2025-01-02T16:15:19.586433015+00:00 DEBUG io_engine::subsys::nvmf::transport:transport.rs:57] Added TCP nvmf transport +[2025-01-02T16:15:19.586441605+00:00 INFO io_engine::core::env:env.rs:875] Using 'MY_POD_IP' environment variable for IP address for NVMF target network interface +[2025-01-02T16:15:19.586499066+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.8 port 4421 *** +[2025-01-02T16:15:19.586509317+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.8 port 8420 *** +[2025-01-02T16:15:19.586512097+00:00 INFO io_engine::subsys::nvmf::target:target.rs:252] nvmf target listening(tcp) on 10.1.0.8:(4421,8420) +[2025-01-02T16:15:19.586515037+00:00 DEBUG io_engine::subsys::nvmf::target:target.rs:329] creating discovery subsystem for target +[2025-01-02T16:15:19.586527257+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:777] Subsystem start in progress... self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.8", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.586541727+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:826] Subsystem start completed: Ok self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.8", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.586545287+00:00 INFO io_engine::subsys::nvmf::target:target.rs:409] nvmf target accepting new connections and is ready to roll..💃 +[2025-01-02T16:15:19.788816116+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'iscsi_poll_group_2' (0x55a12487c310) on core #2 +[2025-01-02T16:15:19.788898248+00:00 INFO io_engine::core::env:env.rs:900] RPC server listening at: /host/tmp/io-engine-3.sock +[2025-01-02T16:15:19.789161543+00:00 WARN io_engine:io-engine.rs:76] Nexus reset is disabled +[2025-01-02T16:15:19.789170123+00:00 WARN io_engine:io-engine.rs:87] Experimental Snapshot Rebuild is enabled +[2025-01-02T16:15:19.789173703+00:00 DEBUG io_engine:io-engine.rs:107] Blob store cluster release on UNMAP is disabled +[2025-01-02T16:15:19.789176573+00:00 INFO io_engine:io-engine.rs:110] Async QPair connection feature ('spdk-async-qpair-connect') is enabled +[2025-01-02T16:15:19.789180554+00:00 INFO io_engine:io-engine.rs:111] Fault injection feature ('fault-injection') is disabled +[2025-01-02T16:15:19.793348538+00:00 INFO io_engine::persistent_store:persistent_store.rs:141] Connected to etcd on endpoint etcd.cluster:2379 +[2025-01-02T16:15:19.793387838+00:00 INFO io_engine::persistent_store:persistent_store.rs:117] Persistent store operation timeout: 10s, number of retries: 30 +[2025-01-02T16:15:19.793432259+00:00 INFO io_engine::grpc::server:server.rs:67] [V1] gRPC server configured at address 10.1.0.8:10124 +[2025-01-02T16:15:19.793562872+00:00 INFO io_engine::subsys::registration::registration_grpc:registration_grpc.rs:203] Registering '"io-engine-3"' with grpc server 10.1.0.8:10124 ... +[2025-01-02T16:15:20.169335179+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node3pool1", uuid: None, disks: ["malloc:///node3pool1?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.169376160+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.169380990+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.169385510+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node3pool1' from 'malloc:///node3pool1?size_mb=32'... +[2025-01-02T16:15:20.169393891+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node3pool1' (65536 blocks): creating bdev +[2025-01-02T16:15:20.171854740+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.171868670+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.171886671+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node3pool1' from 'node3pool1'... +[2025-01-02T16:15:20.172282839+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.172287699+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.172307609+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.172310119+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.172314189+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node3pool1 +[2025-01-02T16:15:20.172317919+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.172319689+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.172321389+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.172323100+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=424µs time.idle=45.7µs +[2025-01-02T16:15:20.172364000+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.172384661+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.172387631+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node3pool1' [node3pool1/22913e32-d454-4bc0-8a4c-8acfdaeda548] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.172405651+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.172407651+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.172409261+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.172410831+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool1", disks: ["malloc:///node3pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=2.99ms time.idle=49.4µs +[2025-01-02T16:15:20.262577620+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node3pool2", uuid: None, disks: ["malloc:///node3pool2?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.262600050+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.262603790+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.262608320+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node3pool2' from 'malloc:///node3pool2?size_mb=32'... +[2025-01-02T16:15:20.262616540+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node3pool2' (65536 blocks): creating bdev +[2025-01-02T16:15:20.275366277+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.275381778+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.275400718+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node3pool2' from 'node3pool2'... +[2025-01-02T16:15:20.275449989+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.275453409+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.275479510+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.275483130+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.275486870+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node3pool2 +[2025-01-02T16:15:20.275491360+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.275493190+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.275495040+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.275496800+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=78.3µs time.idle=53.3µs +[2025-01-02T16:15:20.275544161+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.275573692+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.275576992+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node3pool2' [node3pool2/651a4361-673d-40aa-bad6-c2ae77aa4b1d] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.275592702+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.275594912+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.275596432+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.275597992+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool2", disks: ["malloc:///node3pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=12.9ms time.idle=63.3µs +[2025-01-02T16:15:20.354566464+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node3pool3", uuid: None, disks: ["malloc:///node3pool3?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.354600795+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.354604865+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.354609365+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node3pool3' from 'malloc:///node3pool3?size_mb=32'... +[2025-01-02T16:15:20.354617575+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node3pool3' (65536 blocks): creating bdev +[2025-01-02T16:15:20.356977183+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.356991403+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.357010794+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node3pool3' from 'node3pool3'... +[2025-01-02T16:15:20.357033904+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.357036884+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.357059185+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.357061735+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.357064775+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node3pool3 +[2025-01-02T16:15:20.357068175+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.357070055+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.357071815+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.357073555+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=50.8µs time.idle=46.6µs +[2025-01-02T16:15:20.357120696+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.357141386+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.357143976+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node3pool3' [node3pool3/b2a4eb44-30ea-4935-a58c-adad8acbabd8] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.357160687+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.357162807+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.357164367+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.357166687+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node3pool3", disks: ["malloc:///node3pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=2.51ms time.idle=51.5µs + + +Logs for container io-engine-4: +---------------------------------------- +[2025-01-02T16:15:19.317447411+00:00 INFO io_engine:io-engine.rs:253] Engine responsible for managing I/Os version 1.0.0, revision 17488f4a7da3 (v1.0.0+997) +[2025-01-02T16:15:19.317530732+00:00 INFO io_engine:io-engine.rs:232] free_pages 2MB: 4096 nr_pages 2MB: 4096 +[2025-01-02T16:15:19.317535422+00:00 INFO io_engine:io-engine.rs:233] free_pages 1GB: 0 nr_pages 1GB: 0 +[2025-01-02T16:15:19.317600324+00:00 INFO io_engine:io-engine.rs:284] kernel io_uring support: yes +[2025-01-02T16:15:19.317604494+00:00 INFO io_engine:io-engine.rs:288] kernel nvme initiator multipath support: yes +[2025-01-02T16:15:19.317631344+00:00 INFO io_engine::subsys::config:mod.rs:233] Applying Mayastor configuration settings +[2025-01-02T16:15:19.317635055+00:00 DEBUG io_engine::subsys::config::opts:opts.rs:390] spdk_bdev_nvme_opts { action_on_timeout: 4, timeout_us: 5000000, timeout_admin_us: 5000000, keep_alive_timeout_ms: 10000, transport_retry_count: 0, arbitration_burst: 0, low_priority_weight: 0, medium_priority_weight: 0, high_priority_weight: 0, nvme_adminq_poll_period_us: 1000, nvme_ioq_poll_period_us: 0, io_queue_requests: 0, delay_cmd_submit: true, bdev_retry_count: 0, transport_ack_timeout: 0, ctrlr_loss_timeout_sec: 0, reconnect_delay_sec: 0, fast_io_fail_timeout_sec: 0, disable_auto_failback: false, generate_uuids: true, transport_tos: 0, nvme_error_stat: false, rdma_srq_size: 0, io_path_stat: false, allow_accel_sequence: false, rdma_max_cq_size: 0, rdma_cm_event_timeout_ms: 0, dhchap_digests: 0, dhchap_dhgroups: 0 } +[2025-01-02T16:15:19.317652345+00:00 INFO io_engine::subsys::config::opts:opts.rs:395] NVMe Bdev options successfully applied +[2025-01-02T16:15:19.317654815+00:00 INFO io_engine::subsys::config::opts:opts.rs:538] Bdev options successfully applied +[2025-01-02T16:15:19.317657345+00:00 INFO io_engine::subsys::config::opts:opts.rs:694] Socket options successfully applied +[2025-01-02T16:15:19.317659465+00:00 INFO io_engine::subsys::config::opts:opts.rs:733] I/O buffer options successfully applied +[2025-01-02T16:15:19.317661365+00:00 INFO io_engine::subsys::config:mod.rs:239] Config { + source: None, + nvmf_tgt_conf: NvmfTgtConfig { + name: "mayastor_target", + max_namespaces: 2048, + crdt: [ + 0, + 0, + 0, + ], + opts_tcp: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 131072, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 0, + }, + interface: None, + rdma: None, + opts_rdma: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 8192, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 4095, + }, + }, + nvme_bdev_opts: NvmeBdevOpts { + action_on_timeout: 4, + timeout_us: 5000000, + timeout_admin_us: 5000000, + keep_alive_timeout_ms: 10000, + transport_retry_count: 0, + arbitration_burst: 0, + low_priority_weight: 0, + medium_priority_weight: 0, + high_priority_weight: 0, + nvme_adminq_poll_period_us: 1000, + nvme_ioq_poll_period_us: 0, + io_queue_requests: 0, + delay_cmd_submit: true, + bdev_retry_count: 0, + transport_ack_timeout: 0, + ctrlr_loss_timeout_sec: 0, + reconnect_delay_sec: 0, + fast_io_fail_timeout_sec: 0, + disable_auto_failback: false, + generate_uuids: true, + }, + bdev_opts: BdevOpts { + bdev_io_pool_size: 65535, + bdev_io_cache_size: 512, + iobuf_small_cache_size: 128, + iobuf_large_cache_size: 16, + }, + nexus_opts: NexusOpts { + nvmf_enable: true, + nvmf_discovery_enable: true, + nvmf_nexus_port: 4421, + nvmf_replica_port: 8420, + }, + socket_opts: PosixSocketOpts { + recv_buf_size: 2097152, + send_buf_size: 2097152, + enable_recv_pipe: true, + enable_zero_copy_send: true, + enable_quickack: true, + enable_placement_id: 0, + enable_zerocopy_send_server: true, + enable_zerocopy_send_client: false, + zerocopy_threshold: 0, + }, + iobuf_opts: IoBufOpts { + small_pool_count: 8192, + large_pool_count: 2048, + small_bufsize: 8192, + large_bufsize: 135168, + }, + eal_opts: EalOpts { + reactor_mask: None, + core_list: None, + developer_delay: None, + }, +} +[2025-01-02T16:15:19.317758337+00:00 DEBUG io_engine::core::env:env.rs:750] EAL arguments ["mayastor", "--no-shconf", "-m 0", "--base-virtaddr=0x200000000000", "--file-prefix=mayastor_pid1", "--huge-unlink", "--log-level=lib.eal:6", "--log-level=lib.cryptodev:5", "--log-level=user1:6", "--match-allocations", "-l 3"] +TELEMETRY: No legacy callbacks, legacy socket not created +TELEMETRY: Socket write base info to client failed +[2025-01-02T16:15:19.434462670+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'bdev_io_ctx' with 65535 elements (24 bytes size) successfully created +[2025-01-02T16:15:19.437121614+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'nvme_ctrl_io_ctx' with 65535 elements (72 bytes size) successfully created +[2025-01-02T16:15:19.437150225+00:00 INFO io_engine::core::env:env.rs:1015] Total number of cores available: 1 +[2025-01-02T16:15:19.444678626+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'init_thread' (0x55d473701c10) on core #3 +[2025-01-02T16:15:19.444705217+00:00 INFO io_engine::core::reactor:reactor.rs:156] Init thread ID 1 +[2025-01-02T16:15:19.444708907+00:00 INFO io_engine::core::env:env.rs:1050] All cores locked and loaded! +[2025-01-02T16:15:19.444747558+00:00 DEBUG io_engine::subsys::config:mod.rs:51] mayastor subsystem init +TELEMETRY: Socket write base info to client failed +TELEMETRY: Socket write base info to client failed +TELEMETRY: Socket write base info to client failed +[2025-01-02T16:15:19.585629079+00:00 INFO io_engine::bdev::nexus::nexus_module:nexus_module.rs:36] Initializing Nexus CAS Module +[2025-01-02T16:15:19.585662869+00:00 DEBUG io_engine::subsys::nvmf:mod.rs:85] NVMF subsystem init +[2025-01-02T16:15:19.585693920+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'mayastor_nvmf_tcp_pg_core_3' (0x55d4737c8380) on core #3 +[2025-01-02T16:15:19.585778652+00:00 DEBUG mayastor::spdk:tcp.c:672] *** TCP Transport Init *** +[2025-01-02T16:15:19.586537927+00:00 DEBUG io_engine::subsys::nvmf::transport:transport.rs:57] Added TCP nvmf transport +[2025-01-02T16:15:19.586567958+00:00 INFO io_engine::core::env:env.rs:875] Using 'MY_POD_IP' environment variable for IP address for NVMF target network interface +[2025-01-02T16:15:19.586627519+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.9 port 4421 *** +[2025-01-02T16:15:19.586651989+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.9 port 8420 *** +[2025-01-02T16:15:19.586657180+00:00 INFO io_engine::subsys::nvmf::target:target.rs:252] nvmf target listening(tcp) on 10.1.0.9:(4421,8420) +[2025-01-02T16:15:19.586662040+00:00 DEBUG io_engine::subsys::nvmf::target:target.rs:329] creating discovery subsystem for target +[2025-01-02T16:15:19.586676710+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:777] Subsystem start in progress... self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.9", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.586692590+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:826] Subsystem start completed: Ok self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.9", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.586698940+00:00 INFO io_engine::subsys::nvmf::target:target.rs:409] nvmf target accepting new connections and is ready to roll..💃 +[2025-01-02T16:15:19.823041386+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'iscsi_poll_group_3' (0x55d473980fd0) on core #3 +[2025-01-02T16:15:19.823093447+00:00 INFO io_engine::core::env:env.rs:900] RPC server listening at: /host/tmp/io-engine-4.sock +[2025-01-02T16:15:19.823313772+00:00 WARN io_engine:io-engine.rs:76] Nexus reset is disabled +[2025-01-02T16:15:19.823323632+00:00 WARN io_engine:io-engine.rs:87] Experimental Snapshot Rebuild is enabled +[2025-01-02T16:15:19.823328082+00:00 DEBUG io_engine:io-engine.rs:107] Blob store cluster release on UNMAP is disabled +[2025-01-02T16:15:19.823331332+00:00 INFO io_engine:io-engine.rs:110] Async QPair connection feature ('spdk-async-qpair-connect') is enabled +[2025-01-02T16:15:19.823334212+00:00 INFO io_engine:io-engine.rs:111] Fault injection feature ('fault-injection') is disabled +[2025-01-02T16:15:19.827040117+00:00 INFO io_engine::persistent_store:persistent_store.rs:141] Connected to etcd on endpoint etcd.cluster:2379 +[2025-01-02T16:15:19.827076898+00:00 INFO io_engine::persistent_store:persistent_store.rs:117] Persistent store operation timeout: 10s, number of retries: 30 +[2025-01-02T16:15:19.827113498+00:00 INFO io_engine::grpc::server:server.rs:67] [V1] gRPC server configured at address 10.1.0.9:10124 +[2025-01-02T16:15:19.827252801+00:00 INFO io_engine::subsys::registration::registration_grpc:registration_grpc.rs:203] Registering '"io-engine-4"' with grpc server 10.1.0.9:10124 ... +[2025-01-02T16:15:20.181660328+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node4pool1", uuid: None, disks: ["malloc:///node4pool1?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.181698939+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.181703849+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.181708239+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node4pool1' from 'malloc:///node4pool1?size_mb=32'... +[2025-01-02T16:15:20.181717149+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node4pool1' (65536 blocks): creating bdev +[2025-01-02T16:15:20.184209619+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.184226440+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.184242430+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node4pool1' from 'node4pool1'... +[2025-01-02T16:15:20.184652988+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.184658488+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.184684899+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.184688379+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.184692419+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node4pool1 +[2025-01-02T16:15:20.184696409+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.184699299+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.184701339+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.184703689+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=437µs time.idle=58.4µs +[2025-01-02T16:15:20.184747660+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.184767420+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.184771121+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node4pool1' [node4pool1/0d45f56a-811b-4c3b-b380-0b85f02fbd8e] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.184786151+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.184788771+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.184790351+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.184791891+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool1", disks: ["malloc:///node4pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=3.04ms time.idle=55.5µs +[2025-01-02T16:15:20.285142274+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node4pool2", uuid: None, disks: ["malloc:///node4pool2?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.285163665+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.285167765+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.285171405+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node4pool2' from 'malloc:///node4pool2?size_mb=32'... +[2025-01-02T16:15:20.285179435+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node4pool2' (65536 blocks): creating bdev +[2025-01-02T16:15:20.296361301+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.296378291+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.296394011+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node4pool2' from 'node4pool2'... +[2025-01-02T16:15:20.296447452+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.296451652+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.296474973+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.296478463+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.296481713+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node4pool2 +[2025-01-02T16:15:20.296485113+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.296487023+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.296489023+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.296491473+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=78.0µs time.idle=53.3µs +[2025-01-02T16:15:20.296531574+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.296559605+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.296563335+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node4pool2' [node4pool2/2ba5a8c7-eb49-4c9e-9590-206724f63a4e] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.296580405+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.296583585+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.296585175+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.296586705+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool2", disks: ["malloc:///node4pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=11.4ms time.idle=60.3µs +[2025-01-02T16:15:20.364525685+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node4pool3", uuid: None, disks: ["malloc:///node4pool3?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.364566346+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.364570426+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.364573816+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node4pool3' from 'malloc:///node4pool3?size_mb=32'... +[2025-01-02T16:15:20.364581296+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node4pool3' (65536 blocks): creating bdev +[2025-01-02T16:15:20.366979915+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.366995395+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.367010125+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node4pool3' from 'node4pool3'... +[2025-01-02T16:15:20.367034066+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.367037706+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.367059986+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.367063066+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.367065976+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node4pool3 +[2025-01-02T16:15:20.367069166+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.367071247+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.367073187+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.367075367+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=46.8µs time.idle=49.8µs +[2025-01-02T16:15:20.367121558+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.367142648+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.367145898+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node4pool3' [node4pool3/35cab382-e581-4487-957a-e27d49f50029] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.367161668+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.367164248+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.367165878+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.367167368+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node4pool3", disks: ["malloc:///node4pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=2.55ms time.idle=51.9µs + + +Logs for container io-engine-1: +---------------------------------------- +[2025-01-02T16:15:19.385972893+00:00 INFO io_engine:io-engine.rs:253] Engine responsible for managing I/Os version 1.0.0, revision 17488f4a7da3 (v1.0.0+997) +[2025-01-02T16:15:19.386051184+00:00 INFO io_engine:io-engine.rs:232] free_pages 2MB: 4096 nr_pages 2MB: 4096 +[2025-01-02T16:15:19.386054364+00:00 INFO io_engine:io-engine.rs:233] free_pages 1GB: 0 nr_pages 1GB: 0 +[2025-01-02T16:15:19.386113975+00:00 INFO io_engine:io-engine.rs:284] kernel io_uring support: yes +[2025-01-02T16:15:19.386117355+00:00 INFO io_engine:io-engine.rs:288] kernel nvme initiator multipath support: yes +[2025-01-02T16:15:19.386140326+00:00 INFO io_engine::subsys::config:mod.rs:233] Applying Mayastor configuration settings +[2025-01-02T16:15:19.386142826+00:00 DEBUG io_engine::subsys::config::opts:opts.rs:390] spdk_bdev_nvme_opts { action_on_timeout: 4, timeout_us: 5000000, timeout_admin_us: 5000000, keep_alive_timeout_ms: 10000, transport_retry_count: 0, arbitration_burst: 0, low_priority_weight: 0, medium_priority_weight: 0, high_priority_weight: 0, nvme_adminq_poll_period_us: 1000, nvme_ioq_poll_period_us: 0, io_queue_requests: 0, delay_cmd_submit: true, bdev_retry_count: 0, transport_ack_timeout: 0, ctrlr_loss_timeout_sec: 0, reconnect_delay_sec: 0, fast_io_fail_timeout_sec: 0, disable_auto_failback: false, generate_uuids: true, transport_tos: 0, nvme_error_stat: false, rdma_srq_size: 0, io_path_stat: false, allow_accel_sequence: false, rdma_max_cq_size: 0, rdma_cm_event_timeout_ms: 0, dhchap_digests: 0, dhchap_dhgroups: 0 } +[2025-01-02T16:15:19.386153736+00:00 INFO io_engine::subsys::config::opts:opts.rs:395] NVMe Bdev options successfully applied +[2025-01-02T16:15:19.386155436+00:00 INFO io_engine::subsys::config::opts:opts.rs:538] Bdev options successfully applied +[2025-01-02T16:15:19.386157446+00:00 INFO io_engine::subsys::config::opts:opts.rs:694] Socket options successfully applied +[2025-01-02T16:15:19.386159016+00:00 INFO io_engine::subsys::config::opts:opts.rs:733] I/O buffer options successfully applied +[2025-01-02T16:15:19.386160396+00:00 INFO io_engine::subsys::config:mod.rs:239] Config { + source: None, + nvmf_tgt_conf: NvmfTgtConfig { + name: "mayastor_target", + max_namespaces: 2048, + crdt: [ + 0, + 0, + 0, + ], + opts_tcp: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 131072, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 0, + }, + interface: None, + rdma: None, + opts_rdma: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 8192, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 4095, + }, + }, + nvme_bdev_opts: NvmeBdevOpts { + action_on_timeout: 4, + timeout_us: 5000000, + timeout_admin_us: 5000000, + keep_alive_timeout_ms: 10000, + transport_retry_count: 0, + arbitration_burst: 0, + low_priority_weight: 0, + medium_priority_weight: 0, + high_priority_weight: 0, + nvme_adminq_poll_period_us: 1000, + nvme_ioq_poll_period_us: 0, + io_queue_requests: 0, + delay_cmd_submit: true, + bdev_retry_count: 0, + transport_ack_timeout: 0, + ctrlr_loss_timeout_sec: 0, + reconnect_delay_sec: 0, + fast_io_fail_timeout_sec: 0, + disable_auto_failback: false, + generate_uuids: true, + }, + bdev_opts: BdevOpts { + bdev_io_pool_size: 65535, + bdev_io_cache_size: 512, + iobuf_small_cache_size: 128, + iobuf_large_cache_size: 16, + }, + nexus_opts: NexusOpts { + nvmf_enable: true, + nvmf_discovery_enable: true, + nvmf_nexus_port: 4421, + nvmf_replica_port: 8420, + }, + socket_opts: PosixSocketOpts { + recv_buf_size: 2097152, + send_buf_size: 2097152, + enable_recv_pipe: true, + enable_zero_copy_send: true, + enable_quickack: true, + enable_placement_id: 0, + enable_zerocopy_send_server: true, + enable_zerocopy_send_client: false, + zerocopy_threshold: 0, + }, + iobuf_opts: IoBufOpts { + small_pool_count: 8192, + large_pool_count: 2048, + small_bufsize: 8192, + large_bufsize: 135168, + }, + eal_opts: EalOpts { + reactor_mask: None, + core_list: None, + developer_delay: None, + }, +} +[2025-01-02T16:15:19.386255618+00:00 DEBUG io_engine::core::env:env.rs:750] EAL arguments ["mayastor", "--no-shconf", "-m 0", "--base-virtaddr=0x200000000000", "--file-prefix=mayastor_pid1", "--huge-unlink", "--log-level=lib.eal:6", "--log-level=lib.cryptodev:5", "--log-level=user1:6", "--match-allocations", "-l 0"] +TELEMETRY: No legacy callbacks, legacy socket not created +TELEMETRY: Socket write base info to client failed +[2025-01-02T16:15:19.581278011+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'bdev_io_ctx' with 65535 elements (24 bytes size) successfully created +TELEMETRY: Socket write base info to client failed +[2025-01-02T16:15:19.583853573+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'nvme_ctrl_io_ctx' with 65535 elements (72 bytes size) successfully created +[2025-01-02T16:15:19.583877993+00:00 INFO io_engine::core::env:env.rs:1015] Total number of cores available: 1 +[2025-01-02T16:15:19.593225832+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'init_thread' (0x55f30144abf0) on core #0 +[2025-01-02T16:15:19.593251202+00:00 INFO io_engine::core::reactor:reactor.rs:156] Init thread ID 1 +[2025-01-02T16:15:19.593254623+00:00 INFO io_engine::core::env:env.rs:1050] All cores locked and loaded! +[2025-01-02T16:15:19.593303994+00:00 DEBUG io_engine::subsys::config:mod.rs:51] mayastor subsystem init +[2025-01-02T16:15:19.822386263+00:00 INFO io_engine::bdev::nexus::nexus_module:nexus_module.rs:36] Initializing Nexus CAS Module +[2025-01-02T16:15:19.822437864+00:00 DEBUG io_engine::subsys::nvmf:mod.rs:85] NVMF subsystem init +[2025-01-02T16:15:19.822480685+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'mayastor_nvmf_tcp_pg_core_0' (0x55f301511d80) on core #0 +[2025-01-02T16:15:19.822584807+00:00 DEBUG mayastor::spdk:tcp.c:672] *** TCP Transport Init *** +[2025-01-02T16:15:19.823127808+00:00 DEBUG io_engine::subsys::nvmf::transport:transport.rs:57] Added TCP nvmf transport +[2025-01-02T16:15:19.823136168+00:00 INFO io_engine::core::env:env.rs:875] Using 'MY_POD_IP' environment variable for IP address for NVMF target network interface +[2025-01-02T16:15:19.823191969+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.6 port 4421 *** +[2025-01-02T16:15:19.823205030+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.6 port 8420 *** +[2025-01-02T16:15:19.823208340+00:00 INFO io_engine::subsys::nvmf::target:target.rs:252] nvmf target listening(tcp) on 10.1.0.6:(4421,8420) +[2025-01-02T16:15:19.823213110+00:00 DEBUG io_engine::subsys::nvmf::target:target.rs:329] creating discovery subsystem for target +[2025-01-02T16:15:19.823228550+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:777] Subsystem start in progress... self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.6", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.823242800+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:826] Subsystem start completed: Ok self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.6", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.823247141+00:00 INFO io_engine::subsys::nvmf::target:target.rs:409] nvmf target accepting new connections and is ready to roll..💃 +[2025-01-02T16:15:19.972063021+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'iscsi_poll_group_0' (0x55f3016cad90) on core #0 +[2025-01-02T16:15:19.972133463+00:00 INFO io_engine::core::env:env.rs:900] RPC server listening at: /host/tmp/io-engine-1.sock +[2025-01-02T16:15:19.972360177+00:00 WARN io_engine:io-engine.rs:76] Nexus reset is disabled +[2025-01-02T16:15:19.972367167+00:00 WARN io_engine:io-engine.rs:87] Experimental Snapshot Rebuild is enabled +[2025-01-02T16:15:19.972369528+00:00 DEBUG io_engine:io-engine.rs:107] Blob store cluster release on UNMAP is disabled +[2025-01-02T16:15:19.972371098+00:00 INFO io_engine:io-engine.rs:110] Async QPair connection feature ('spdk-async-qpair-connect') is enabled +[2025-01-02T16:15:19.972372538+00:00 INFO io_engine:io-engine.rs:111] Fault injection feature ('fault-injection') is disabled +[2025-01-02T16:15:19.976110543+00:00 INFO io_engine::persistent_store:persistent_store.rs:141] Connected to etcd on endpoint etcd.cluster:2379 +[2025-01-02T16:15:19.976159994+00:00 INFO io_engine::persistent_store:persistent_store.rs:117] Persistent store operation timeout: 10s, number of retries: 30 +[2025-01-02T16:15:19.976203505+00:00 INFO io_engine::grpc::server:server.rs:67] [V1] gRPC server configured at address 10.1.0.6:10124 +[2025-01-02T16:15:19.976335987+00:00 INFO io_engine::subsys::registration::registration_grpc:registration_grpc.rs:203] Registering '"io-engine-1"' with grpc server 10.1.0.6:10124 ... +[2025-01-02T16:15:20.143578560+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node1pool1", uuid: None, disks: ["malloc:///node1pool1?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.143628001+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.143634591+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.143641671+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node1pool1' from 'malloc:///node1pool1?size_mb=32'... +[2025-01-02T16:15:20.143652481+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node1pool1' (65536 blocks): creating bdev +[2025-01-02T16:15:20.145973088+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.145990079+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.146005849+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node1pool1' from 'node1pool1'... +[2025-01-02T16:15:20.146435098+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.146441038+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.146464278+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.146467668+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.146472128+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node1pool1 +[2025-01-02T16:15:20.146476538+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.146478399+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.146480279+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.146482419+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=456µs time.idle=54.7µs +[2025-01-02T16:15:20.146528880+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.146554300+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.146559190+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node1pool1' [node1pool1/01a0b44b-13d2-445c-a0ad-e8d53252288e] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.146578991+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.146582421+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.146584091+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.146585801+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool1", disks: ["malloc:///node1pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=2.90ms time.idle=60.6µs +[2025-01-02T16:15:20.205614131+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node1pool2", uuid: None, disks: ["malloc:///node1pool2?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.205646592+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.205651702+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.205657802+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node1pool2' from 'malloc:///node1pool2?size_mb=32'... +[2025-01-02T16:15:20.205668282+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node1pool2' (65536 blocks): creating bdev +[2025-01-02T16:15:20.222308788+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.222325228+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.222347818+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node1pool2' from 'node1pool2'... +[2025-01-02T16:15:20.222393429+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.222397309+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.222425770+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.222428810+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.222432320+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node1pool2 +[2025-01-02T16:15:20.222435530+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.222437590+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.222439440+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.222441460+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=77.2µs time.idle=56.8µs +[2025-01-02T16:15:20.222488191+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.222508672+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.222511872+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node1pool2' [node1pool2/87fc5898-4bbf-4150-b8ea-96b86d83ff87] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.222526402+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.222529002+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.222530642+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.222532132+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool2", disks: ["malloc:///node1pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=16.8ms time.idle=58.4µs +[2025-01-02T16:15:20.332405447+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node1pool3", uuid: None, disks: ["malloc:///node1pool3?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.332431468+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.332436338+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.332442298+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node1pool3' from 'malloc:///node1pool3?size_mb=32'... +[2025-01-02T16:15:20.332450968+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node1pool3' (65536 blocks): creating bdev +[2025-01-02T16:15:20.334844077+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.334859157+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.334873627+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node1pool3' from 'node1pool3'... +[2025-01-02T16:15:20.334897138+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.334900708+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.334925468+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.334928558+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.334932198+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node1pool3 +[2025-01-02T16:15:20.334935379+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.334937559+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.334940049+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.334942429+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=47.4µs time.idle=52.0µs +[2025-01-02T16:15:20.334988510+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.335008720+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.335011800+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node1pool3' [node1pool3/5455d8f6-0bd1-4e0a-a2cb-c83f96e2fb4d] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.335026660+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.335029210+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.335030720+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.335032411+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node1pool3", disks: ["malloc:///node1pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=2.55ms time.idle=54.3µs + + +Logs for container io-engine-2: +---------------------------------------- +[2025-01-02T16:15:19.385968833+00:00 INFO io_engine:io-engine.rs:253] Engine responsible for managing I/Os version 1.0.0, revision 17488f4a7da3 (v1.0.0+997) +[2025-01-02T16:15:19.386043014+00:00 INFO io_engine:io-engine.rs:232] free_pages 2MB: 4096 nr_pages 2MB: 4096 +[2025-01-02T16:15:19.386045854+00:00 INFO io_engine:io-engine.rs:233] free_pages 1GB: 0 nr_pages 1GB: 0 +[2025-01-02T16:15:19.386104875+00:00 INFO io_engine:io-engine.rs:284] kernel io_uring support: yes +[2025-01-02T16:15:19.386107995+00:00 INFO io_engine:io-engine.rs:288] kernel nvme initiator multipath support: yes +[2025-01-02T16:15:19.386131036+00:00 INFO io_engine::subsys::config:mod.rs:233] Applying Mayastor configuration settings +[2025-01-02T16:15:19.386133836+00:00 DEBUG io_engine::subsys::config::opts:opts.rs:390] spdk_bdev_nvme_opts { action_on_timeout: 4, timeout_us: 5000000, timeout_admin_us: 5000000, keep_alive_timeout_ms: 10000, transport_retry_count: 0, arbitration_burst: 0, low_priority_weight: 0, medium_priority_weight: 0, high_priority_weight: 0, nvme_adminq_poll_period_us: 1000, nvme_ioq_poll_period_us: 0, io_queue_requests: 0, delay_cmd_submit: true, bdev_retry_count: 0, transport_ack_timeout: 0, ctrlr_loss_timeout_sec: 0, reconnect_delay_sec: 0, fast_io_fail_timeout_sec: 0, disable_auto_failback: false, generate_uuids: true, transport_tos: 0, nvme_error_stat: false, rdma_srq_size: 0, io_path_stat: false, allow_accel_sequence: false, rdma_max_cq_size: 0, rdma_cm_event_timeout_ms: 0, dhchap_digests: 0, dhchap_dhgroups: 0 } +[2025-01-02T16:15:19.386144116+00:00 INFO io_engine::subsys::config::opts:opts.rs:395] NVMe Bdev options successfully applied +[2025-01-02T16:15:19.386145856+00:00 INFO io_engine::subsys::config::opts:opts.rs:538] Bdev options successfully applied +[2025-01-02T16:15:19.386148016+00:00 INFO io_engine::subsys::config::opts:opts.rs:694] Socket options successfully applied +[2025-01-02T16:15:19.386149566+00:00 INFO io_engine::subsys::config::opts:opts.rs:733] I/O buffer options successfully applied +[2025-01-02T16:15:19.386150886+00:00 INFO io_engine::subsys::config:mod.rs:239] Config { + source: None, + nvmf_tgt_conf: NvmfTgtConfig { + name: "mayastor_target", + max_namespaces: 2048, + crdt: [ + 0, + 0, + 0, + ], + opts_tcp: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 131072, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 0, + }, + interface: None, + rdma: None, + opts_rdma: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 8192, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 4095, + }, + }, + nvme_bdev_opts: NvmeBdevOpts { + action_on_timeout: 4, + timeout_us: 5000000, + timeout_admin_us: 5000000, + keep_alive_timeout_ms: 10000, + transport_retry_count: 0, + arbitration_burst: 0, + low_priority_weight: 0, + medium_priority_weight: 0, + high_priority_weight: 0, + nvme_adminq_poll_period_us: 1000, + nvme_ioq_poll_period_us: 0, + io_queue_requests: 0, + delay_cmd_submit: true, + bdev_retry_count: 0, + transport_ack_timeout: 0, + ctrlr_loss_timeout_sec: 0, + reconnect_delay_sec: 0, + fast_io_fail_timeout_sec: 0, + disable_auto_failback: false, + generate_uuids: true, + }, + bdev_opts: BdevOpts { + bdev_io_pool_size: 65535, + bdev_io_cache_size: 512, + iobuf_small_cache_size: 128, + iobuf_large_cache_size: 16, + }, + nexus_opts: NexusOpts { + nvmf_enable: true, + nvmf_discovery_enable: true, + nvmf_nexus_port: 4421, + nvmf_replica_port: 8420, + }, + socket_opts: PosixSocketOpts { + recv_buf_size: 2097152, + send_buf_size: 2097152, + enable_recv_pipe: true, + enable_zero_copy_send: true, + enable_quickack: true, + enable_placement_id: 0, + enable_zerocopy_send_server: true, + enable_zerocopy_send_client: false, + zerocopy_threshold: 0, + }, + iobuf_opts: IoBufOpts { + small_pool_count: 8192, + large_pool_count: 2048, + small_bufsize: 8192, + large_bufsize: 135168, + }, + eal_opts: EalOpts { + reactor_mask: None, + core_list: None, + developer_delay: None, + }, +} +[2025-01-02T16:15:19.386227218+00:00 DEBUG io_engine::core::env:env.rs:750] EAL arguments ["mayastor", "--no-shconf", "-m 0", "--base-virtaddr=0x200000000000", "--file-prefix=mayastor_pid1", "--huge-unlink", "--log-level=lib.eal:6", "--log-level=lib.cryptodev:5", "--log-level=user1:6", "--match-allocations", "-l 1"] +TELEMETRY: No legacy callbacks, legacy socket not created +[2025-01-02T16:15:19.582497356+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'bdev_io_ctx' with 65535 elements (24 bytes size) successfully created +TELEMETRY: Socket write base info to client failed +[2025-01-02T16:15:19.585335483+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'nvme_ctrl_io_ctx' with 65535 elements (72 bytes size) successfully created +[2025-01-02T16:15:19.585360533+00:00 INFO io_engine::core::env:env.rs:1015] Total number of cores available: 1 +[2025-01-02T16:15:19.597862135+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'init_thread' (0x564a82a13c10) on core #1 +[2025-01-02T16:15:19.597887046+00:00 INFO io_engine::core::reactor:reactor.rs:156] Init thread ID 1 +[2025-01-02T16:15:19.597890006+00:00 INFO io_engine::core::env:env.rs:1050] All cores locked and loaded! +[2025-01-02T16:15:19.597919067+00:00 DEBUG io_engine::subsys::config:mod.rs:51] mayastor subsystem init +[2025-01-02T16:15:19.822694469+00:00 INFO io_engine::bdev::nexus::nexus_module:nexus_module.rs:36] Initializing Nexus CAS Module +[2025-01-02T16:15:19.822717360+00:00 DEBUG io_engine::subsys::nvmf:mod.rs:85] NVMF subsystem init +[2025-01-02T16:15:19.822748480+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'mayastor_nvmf_tcp_pg_core_1' (0x564a82ada7f0) on core #1 +[2025-01-02T16:15:19.822803212+00:00 DEBUG mayastor::spdk:tcp.c:672] *** TCP Transport Init *** +[2025-01-02T16:15:19.823350453+00:00 DEBUG io_engine::subsys::nvmf::transport:transport.rs:57] Added TCP nvmf transport +[2025-01-02T16:15:19.823360013+00:00 INFO io_engine::core::env:env.rs:875] Using 'MY_POD_IP' environment variable for IP address for NVMF target network interface +[2025-01-02T16:15:19.823393213+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.7 port 4421 *** +[2025-01-02T16:15:19.823403284+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.7 port 8420 *** +[2025-01-02T16:15:19.823406484+00:00 INFO io_engine::subsys::nvmf::target:target.rs:252] nvmf target listening(tcp) on 10.1.0.7:(4421,8420) +[2025-01-02T16:15:19.823408994+00:00 DEBUG io_engine::subsys::nvmf::target:target.rs:329] creating discovery subsystem for target +[2025-01-02T16:15:19.823416994+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:777] Subsystem start in progress... self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.7", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.823426664+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:826] Subsystem start completed: Ok self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.7", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.823430624+00:00 INFO io_engine::subsys::nvmf::target:target.rs:409] nvmf target accepting new connections and is ready to roll..💃 +[2025-01-02T16:15:19.974740815+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'iscsi_poll_group_1' (0x564a82c936d0) on core #1 +[2025-01-02T16:15:19.974796327+00:00 INFO io_engine::core::env:env.rs:900] RPC server listening at: /host/tmp/io-engine-2.sock +[2025-01-02T16:15:19.975020431+00:00 WARN io_engine:io-engine.rs:76] Nexus reset is disabled +[2025-01-02T16:15:19.975029231+00:00 WARN io_engine:io-engine.rs:87] Experimental Snapshot Rebuild is enabled +[2025-01-02T16:15:19.975032771+00:00 DEBUG io_engine:io-engine.rs:107] Blob store cluster release on UNMAP is disabled +[2025-01-02T16:15:19.975037171+00:00 INFO io_engine:io-engine.rs:110] Async QPair connection feature ('spdk-async-qpair-connect') is enabled +[2025-01-02T16:15:19.975041561+00:00 INFO io_engine:io-engine.rs:111] Fault injection feature ('fault-injection') is disabled +[2025-01-02T16:15:19.978941000+00:00 INFO io_engine::persistent_store:persistent_store.rs:141] Connected to etcd on endpoint etcd.cluster:2379 +[2025-01-02T16:15:19.978968041+00:00 INFO io_engine::persistent_store:persistent_store.rs:117] Persistent store operation timeout: 10s, number of retries: 30 +[2025-01-02T16:15:19.978999761+00:00 INFO io_engine::grpc::server:server.rs:67] [V1] gRPC server configured at address 10.1.0.7:10124 +[2025-01-02T16:15:19.979103103+00:00 INFO io_engine::subsys::registration::registration_grpc:registration_grpc.rs:203] Registering '"io-engine-2"' with grpc server 10.1.0.7:10124 ... +[2025-01-02T16:15:20.158122343+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node2pool1", uuid: None, disks: ["malloc:///node2pool1?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.158161234+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.158167514+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.158173494+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node2pool1' from 'malloc:///node2pool1?size_mb=32'... +[2025-01-02T16:15:20.158185455+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node2pool1' (65536 blocks): creating bdev +[2025-01-02T16:15:20.160779167+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.160797087+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.160814157+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node2pool1' from 'node2pool1'... +[2025-01-02T16:15:20.161321648+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.161330578+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.161359899+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.161366189+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.161372219+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node2pool1 +[2025-01-02T16:15:20.161377049+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.161379719+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.161382359+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.161385049+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=538µs time.idle=69.0µs +[2025-01-02T16:15:20.161448350+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.161475691+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.161481041+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node2pool1' [node2pool1/3f1d8307-d785-4bbc-8041-8c070b6c628b] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.161502141+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.161505671+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.161507821+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.161510192+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool1", disks: ["malloc:///node2pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=3.28ms time.idle=69.2µs +[2025-01-02T16:15:20.232138726+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node2pool2", uuid: None, disks: ["malloc:///node2pool2?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.232165456+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.232170086+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.232174706+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node2pool2' from 'malloc:///node2pool2?size_mb=32'... +[2025-01-02T16:15:20.232183507+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node2pool2' (65536 blocks): creating bdev +[2025-01-02T16:15:20.252340723+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.252357853+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.252374014+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node2pool2' from 'node2pool2'... +[2025-01-02T16:15:20.252420445+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.252424255+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.252449305+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.252452105+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.252455515+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node2pool2 +[2025-01-02T16:15:20.252459575+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.252461365+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.252463625+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.252466186+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=72.4µs time.idle=54.1µs +[2025-01-02T16:15:20.252508226+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.252528727+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.252531737+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node2pool2' [node2pool2/6e8a0dd3-7702-4776-9466-fb1815d916f0] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.252555977+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.252558717+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.252560297+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.252562747+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool2", disks: ["malloc:///node2pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=20.3ms time.idle=55.5µs +[2025-01-02T16:15:20.344303387+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node2pool3", uuid: None, disks: ["malloc:///node2pool3?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.344326568+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.344330378+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.344334048+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node2pool3' from 'malloc:///node2pool3?size_mb=32'... +[2025-01-02T16:15:20.344341658+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node2pool3' (65536 blocks): creating bdev +[2025-01-02T16:15:20.346756817+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.346772487+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.346788128+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node2pool3' from 'node2pool3'... +[2025-01-02T16:15:20.346811738+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.346815248+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.346832108+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.346834928+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.346838259+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node2pool3 +[2025-01-02T16:15:20.346842269+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.346844089+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.346846259+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.346848399+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=48.8µs time.idle=43.7µs +[2025-01-02T16:15:20.346899520+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.346920720+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.346923750+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node2pool3' [node2pool3/5162164a-61a2-492a-9a5e-cd07b758388a] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.346939881+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.346942311+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.346943861+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.346945991+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node2pool3", disks: ["malloc:///node2pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=2.57ms time.idle=46.6µs + + +Logs for container io-engine-5: +---------------------------------------- +[2025-01-02T16:15:19.429533721+00:00 INFO io_engine:io-engine.rs:253] Engine responsible for managing I/Os version 1.0.0, revision 17488f4a7da3 (v1.0.0+997) +[2025-01-02T16:15:19.429619313+00:00 INFO io_engine:io-engine.rs:232] free_pages 2MB: 4095 nr_pages 2MB: 4096 +[2025-01-02T16:15:19.429622343+00:00 INFO io_engine:io-engine.rs:233] free_pages 1GB: 0 nr_pages 1GB: 0 +[2025-01-02T16:15:19.429674794+00:00 INFO io_engine:io-engine.rs:284] kernel io_uring support: yes +[2025-01-02T16:15:19.429677954+00:00 INFO io_engine:io-engine.rs:288] kernel nvme initiator multipath support: yes +[2025-01-02T16:15:19.429706485+00:00 INFO io_engine::subsys::config:mod.rs:233] Applying Mayastor configuration settings +[2025-01-02T16:15:19.429709215+00:00 DEBUG io_engine::subsys::config::opts:opts.rs:390] spdk_bdev_nvme_opts { action_on_timeout: 4, timeout_us: 5000000, timeout_admin_us: 5000000, keep_alive_timeout_ms: 10000, transport_retry_count: 0, arbitration_burst: 0, low_priority_weight: 0, medium_priority_weight: 0, high_priority_weight: 0, nvme_adminq_poll_period_us: 1000, nvme_ioq_poll_period_us: 0, io_queue_requests: 0, delay_cmd_submit: true, bdev_retry_count: 0, transport_ack_timeout: 0, ctrlr_loss_timeout_sec: 0, reconnect_delay_sec: 0, fast_io_fail_timeout_sec: 0, disable_auto_failback: false, generate_uuids: true, transport_tos: 0, nvme_error_stat: false, rdma_srq_size: 0, io_path_stat: false, allow_accel_sequence: false, rdma_max_cq_size: 0, rdma_cm_event_timeout_ms: 0, dhchap_digests: 0, dhchap_dhgroups: 0 } +[2025-01-02T16:15:19.429719495+00:00 INFO io_engine::subsys::config::opts:opts.rs:395] NVMe Bdev options successfully applied +[2025-01-02T16:15:19.429721215+00:00 INFO io_engine::subsys::config::opts:opts.rs:538] Bdev options successfully applied +[2025-01-02T16:15:19.429723265+00:00 INFO io_engine::subsys::config::opts:opts.rs:694] Socket options successfully applied +[2025-01-02T16:15:19.429725435+00:00 INFO io_engine::subsys::config::opts:opts.rs:733] I/O buffer options successfully applied +[2025-01-02T16:15:19.429726765+00:00 INFO io_engine::subsys::config:mod.rs:239] Config { + source: None, + nvmf_tgt_conf: NvmfTgtConfig { + name: "mayastor_target", + max_namespaces: 2048, + crdt: [ + 0, + 0, + 0, + ], + opts_tcp: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 131072, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 0, + }, + interface: None, + rdma: None, + opts_rdma: NvmfTransportOpts { + max_queue_depth: 32, + max_qpairs_per_ctrl: 32, + in_capsule_data_size: 4096, + max_io_size: 131072, + io_unit_size: 8192, + max_aq_depth: 32, + num_shared_buf: 2047, + buf_cache_size: 64, + dif_insert_or_strip: false, + abort_timeout_sec: 1, + acceptor_poll_rate: 10000, + zcopy: true, + ack_timeout: 0, + data_wr_pool_size: 4095, + }, + }, + nvme_bdev_opts: NvmeBdevOpts { + action_on_timeout: 4, + timeout_us: 5000000, + timeout_admin_us: 5000000, + keep_alive_timeout_ms: 10000, + transport_retry_count: 0, + arbitration_burst: 0, + low_priority_weight: 0, + medium_priority_weight: 0, + high_priority_weight: 0, + nvme_adminq_poll_period_us: 1000, + nvme_ioq_poll_period_us: 0, + io_queue_requests: 0, + delay_cmd_submit: true, + bdev_retry_count: 0, + transport_ack_timeout: 0, + ctrlr_loss_timeout_sec: 0, + reconnect_delay_sec: 0, + fast_io_fail_timeout_sec: 0, + disable_auto_failback: false, + generate_uuids: true, + }, + bdev_opts: BdevOpts { + bdev_io_pool_size: 65535, + bdev_io_cache_size: 512, + iobuf_small_cache_size: 128, + iobuf_large_cache_size: 16, + }, + nexus_opts: NexusOpts { + nvmf_enable: true, + nvmf_discovery_enable: true, + nvmf_nexus_port: 4421, + nvmf_replica_port: 8420, + }, + socket_opts: PosixSocketOpts { + recv_buf_size: 2097152, + send_buf_size: 2097152, + enable_recv_pipe: true, + enable_zero_copy_send: true, + enable_quickack: true, + enable_placement_id: 0, + enable_zerocopy_send_server: true, + enable_zerocopy_send_client: false, + zerocopy_threshold: 0, + }, + iobuf_opts: IoBufOpts { + small_pool_count: 8192, + large_pool_count: 2048, + small_bufsize: 8192, + large_bufsize: 135168, + }, + eal_opts: EalOpts { + reactor_mask: None, + core_list: None, + developer_delay: None, + }, +} +[2025-01-02T16:15:19.429801066+00:00 DEBUG io_engine::core::env:env.rs:750] EAL arguments ["mayastor", "--no-shconf", "-m 0", "--base-virtaddr=0x200000000000", "--file-prefix=mayastor_pid1", "--huge-unlink", "--log-level=lib.eal:6", "--log-level=lib.cryptodev:5", "--log-level=user1:6", "--match-allocations", "-l 4"] +TELEMETRY: No legacy callbacks, legacy socket not created +[2025-01-02T16:15:19.600174352+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'bdev_io_ctx' with 65535 elements (24 bytes size) successfully created +[2025-01-02T16:15:19.668560221+00:00 INFO io_engine::core::mempool:mempool.rs:48] Memory pool 'nvme_ctrl_io_ctx' with 65535 elements (72 bytes size) successfully created +[2025-01-02T16:15:19.668591582+00:00 INFO io_engine::core::env:env.rs:1015] Total number of cores available: 1 +[2025-01-02T16:15:19.824367013+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'init_thread' (0x560c1e164e90) on core #4 +[2025-01-02T16:15:19.824389773+00:00 INFO io_engine::core::reactor:reactor.rs:156] Init thread ID 1 +[2025-01-02T16:15:19.824395654+00:00 INFO io_engine::core::env:env.rs:1050] All cores locked and loaded! +[2025-01-02T16:15:19.824431934+00:00 DEBUG io_engine::subsys::config:mod.rs:51] mayastor subsystem init +[2025-01-02T16:15:19.973201694+00:00 INFO io_engine::bdev::nexus::nexus_module:nexus_module.rs:36] Initializing Nexus CAS Module +[2025-01-02T16:15:19.973228555+00:00 DEBUG io_engine::subsys::nvmf:mod.rs:85] NVMF subsystem init +[2025-01-02T16:15:19.973263206+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'mayastor_nvmf_tcp_pg_core_4' (0x560c1e215ec0) on core #4 +[2025-01-02T16:15:19.973333657+00:00 DEBUG mayastor::spdk:tcp.c:672] *** TCP Transport Init *** +[2025-01-02T16:15:19.973934999+00:00 DEBUG io_engine::subsys::nvmf::transport:transport.rs:57] Added TCP nvmf transport +[2025-01-02T16:15:19.973945899+00:00 INFO io_engine::core::env:env.rs:875] Using 'MY_POD_IP' environment variable for IP address for NVMF target network interface +[2025-01-02T16:15:19.974011701+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.10 port 4421 *** +[2025-01-02T16:15:19.974039591+00:00 DEBUG mayastor::spdk:tcp.c:968] *** NVMe/TCP Target Listening on 10.1.0.10 port 8420 *** +[2025-01-02T16:15:19.974046371+00:00 INFO io_engine::subsys::nvmf::target:target.rs:252] nvmf target listening(tcp) on 10.1.0.10:(4421,8420) +[2025-01-02T16:15:19.974052401+00:00 DEBUG io_engine::subsys::nvmf::target:target.rs:329] creating discovery subsystem for target +[2025-01-02T16:15:19.974069382+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:777] Subsystem start in progress... self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.10", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.974089542+00:00 INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:826] Subsystem start completed: Ok self=NvmfSubsystem { id: 0, subtype: "Discovery", subnqn: "nqn.2014-08.org.nvmexpress.discovery", sn: "00000000000000000000", mn: "Mayastor NVMe controller", allow_any_host: true, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "10.1.0.10", trsvcid: "8420" }]) } +[2025-01-02T16:15:19.974098262+00:00 INFO io_engine::subsys::nvmf::target:target.rs:409] nvmf target accepting new connections and is ready to roll..💃 +[2025-01-02T16:15:20.011563088+00:00 INFO io_engine::core::reactor:reactor.rs:180] Scheduled SPDK thread 'iscsi_poll_group_4' (0x560c1e3cedd0) on core #4 +[2025-01-02T16:15:20.011617449+00:00 INFO io_engine::core::env:env.rs:900] RPC server listening at: /host/tmp/io-engine-5.sock +[2025-01-02T16:15:20.011761332+00:00 WARN io_engine:io-engine.rs:76] Nexus reset is disabled +[2025-01-02T16:15:20.011766042+00:00 WARN io_engine:io-engine.rs:87] Experimental Snapshot Rebuild is enabled +[2025-01-02T16:15:20.011767932+00:00 DEBUG io_engine:io-engine.rs:107] Blob store cluster release on UNMAP is disabled +[2025-01-02T16:15:20.011769482+00:00 INFO io_engine:io-engine.rs:110] Async QPair connection feature ('spdk-async-qpair-connect') is enabled +[2025-01-02T16:15:20.011770952+00:00 INFO io_engine:io-engine.rs:111] Fault injection feature ('fault-injection') is disabled +[2025-01-02T16:15:20.015909376+00:00 INFO io_engine::persistent_store:persistent_store.rs:141] Connected to etcd on endpoint etcd.cluster:2379 +[2025-01-02T16:15:20.015934576+00:00 INFO io_engine::persistent_store:persistent_store.rs:117] Persistent store operation timeout: 10s, number of retries: 30 +[2025-01-02T16:15:20.015968307+00:00 INFO io_engine::grpc::server:server.rs:67] [V1] gRPC server configured at address 10.1.0.10:10124 +[2025-01-02T16:15:20.016062079+00:00 INFO io_engine::subsys::registration::registration_grpc:registration_grpc.rs:203] Registering '"io-engine-5"' with grpc server 10.1.0.10:10124 ... +[2025-01-02T16:15:20.193800903+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node5pool1", uuid: None, disks: ["malloc:///node5pool1?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.193842424+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.193847634+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.193854784+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node5pool1' from 'malloc:///node5pool1?size_mb=32'... +[2025-01-02T16:15:20.193866794+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node5pool1' (65536 blocks): creating bdev +[2025-01-02T16:15:20.196296513+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.196309823+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.196324103+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node5pool1' from 'node5pool1'... +[2025-01-02T16:15:20.196748532+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.196754752+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.196783123+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.196786253+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.196790663+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node5pool1 +[2025-01-02T16:15:20.196794383+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.196796253+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.196797953+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.196799863+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=448µs time.idle=56.1µs +[2025-01-02T16:15:20.196853714+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.196873235+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.196875945+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node5pool1' [node5pool1/36988c87-520e-407c-8c61-cbb97bbef13a] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.196894155+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.196896155+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.196897755+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.196899275+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool1", disks: ["malloc:///node5pool1?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=3.00ms time.idle=56.9µs +[2025-01-02T16:15:20.306355272+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node5pool2", uuid: None, disks: ["malloc:///node5pool2?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.306380703+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.306385263+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.306390933+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node5pool2' from 'malloc:///node5pool2?size_mb=32'... +[2025-01-02T16:15:20.306401783+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node5pool2' (65536 blocks): creating bdev +[2025-01-02T16:15:20.321471747+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.321486797+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.321501788+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node5pool2' from 'node5pool2'... +[2025-01-02T16:15:20.321560339+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.321564759+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.321602000+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.321605590+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.321609130+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node5pool2 +[2025-01-02T16:15:20.321614210+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.321616830+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.321619720+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.321622400+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=85.0µs time.idle=66.6µs +[2025-01-02T16:15:20.321669481+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.321694911+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.321698402+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node5pool2' [node5pool2/bd5e0cb7-6a9f-46bc-bacb-50ac84c8687d] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.321716162+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.321718522+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.321720132+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.321724512+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool2", disks: ["malloc:///node5pool2?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=15.3ms time.idle=74.1µs +[2025-01-02T16:15:20.375150659+00:00 INFO io_engine::grpc::v1::pool:pool.rs:469] CreatePoolRequest { name: "node5pool3", uuid: None, disks: ["malloc:///node5pool3?size_mb=32"], pooltype: Lvs, cluster_size: None, md_args: None } +[2025-01-02T16:15:20.375177510+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] new +[2025-01-02T16:15:20.375181680+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.375187510+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:492] Creating or importing lvs 'node5pool3' from 'malloc:///node5pool3?size_mb=32'... +[2025-01-02T16:15:20.375198510+00:00 DEBUG io_engine::bdev::malloc:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:malloc.rs:166] Malloc 'node5pool3' (65536 blocks): creating bdev +[2025-01-02T16:15:20.377509827+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] new +[2025-01-02T16:15:20.377525857+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.377541918+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:232] Trying to import lvs 'node5pool3' from 'node5pool3'... +[2025-01-02T16:15:20.377578678+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.377582888+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.377610299+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.377613359+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.377617109+00:00 ERROR io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] error=: cannot import LVS, failed to import pool node5pool3 +[2025-01-02T16:15:20.377620699+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.377622489+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] enter +[2025-01-02T16:15:20.377624199+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] exit +[2025-01-02T16:15:20.377626149+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:import_from_args{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:304] close time.busy=62.0µs time.idle=55.1µs +[2025-01-02T16:15:20.377680400+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.377700271+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.377702831+00:00 INFO io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:476] Lvs 'node5pool3' [node5pool3/2fe44623-db41-4e97-b65e-0c9a45c16cd3] (28.00 MiB/28.00 MiB): new lvs created successfully +[2025-01-02T16:15:20.377719591+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.377721771+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] enter +[2025-01-02T16:15:20.377723561+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] exit +[2025-01-02T16:15:20.377725211+00:00 DEBUG io_engine::lvs::lvs_store:create_or_import{args=PoolArgs { name: "node5pool3", disks: ["malloc:///node5pool3?size_mb=32"], uuid: None, cluster_size: None, md_args: None, backend: Lvs }}:lvs_store.rs:488] close time.busy=2.49ms time.idle=55.5µs + + +Logs for container rest: +---------------------------------------- +Control plane REST server (debug) revision 740b973c6430 (v2.2.0-rc.1+826) +Using options: CliArgs { https: "rest:8080", http: Some("rest:8081"), core_grpc: https://core:50051/, core_liveness_check_frequency: 120s, json_grpc: None, cert_file: None, key_file: None, dummy_certificates: true, jaeger: Some("jaeger.cluster:4317"), jwk: None, no_auth: true, request_timeout: Duration(5s), tracing_tags: [], no_min_timeouts: false, workers: 1, max_workers: 8, fmt_style: Pretty, ansi_colors: true } + 2025-01-02T16:15:18.807428Z ERROR grpc::operations::node::client: error: Unavailable: status: Unavailable, message: "tcp connect error: Connection refused (os error 111)", details: [], metadata: MetadataMap { headers: {} } + at control-plane/grpc/src/operations/node/client.rs:74 + in grpc::operations::node::client::NodeClient::probe with _ctx: None + + 2025-01-02T16:15:18.823720Z  INFO actix_server::builder: starting 1 workers + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-server-2.5.0/src/builder.rs:272 + + 2025-01-02T16:15:18.823753Z  INFO actix_server::server: Actix runtime found; starting in Actix runtime + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-server-2.5.0/src/server.rs:191 + + 2025-01-02T16:15:18.823764Z  INFO actix_server::server: starting service: "actix-web-service-10.1.0.5:8080", workers: 1, listening on: 10.1.0.5:8080 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-server-2.5.0/src/server.rs:197 + + 2025-01-02T16:15:18.823773Z  INFO actix_server::server: starting service: "actix-web-service-10.1.0.5:8081", workers: 1, listening on: 10.1.0.5:8081 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-server-2.5.0/src/server.rs:197 + + 2025-01-02T16:15:19.040030Z  INFO actix_web::middleware::logger: 10.1.0.1 "GET /v0/api/spec HTTP/1.1" 200 87584 "-" "-" 0.025295 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:19.107720Z  INFO actix_web::middleware::logger: 10.1.0.1 "GET /v0/api/spec HTTP/1.1" 200 87584 "-" "-" 0.025376 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.103068Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-1/label/zone-us=us-west-1?overwrite=false HTTP/1.1" 200 382 "-" "OpenAPI-Generator/1.0.0/python" 0.008347 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.110487Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-2/label/zone-ap=ap-south-1?overwrite=false HTTP/1.1" 200 383 "-" "OpenAPI-Generator/1.0.0/python" 0.002516 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.114785Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-3/label/zone-eu=eu-west-3?overwrite=false HTTP/1.1" 200 382 "-" "OpenAPI-Generator/1.0.0/python" 0.002359 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.118633Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-4/label/zone-us=us-west-1?overwrite=false HTTP/1.1" 200 382 "-" "OpenAPI-Generator/1.0.0/python" 0.002289 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.122748Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-4/label/zone-ap=ap-south-1?overwrite=false HTTP/1.1" 200 405 "-" "OpenAPI-Generator/1.0.0/python" 0.002672 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.126683Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-4/label/zone-eu=eu-west-3?overwrite=false HTTP/1.1" 200 427 "-" "OpenAPI-Generator/1.0.0/python" 0.002302 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.130334Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-5/label/zone-us=different-value?overwrite=false HTTP/1.1" 200 390 "-" "OpenAPI-Generator/1.0.0/python" 0.002265 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.133996Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-5/label/zone-ap=different-value?overwrite=false HTTP/1.1" 200 418 "-" "OpenAPI-Generator/1.0.0/python" 0.002234 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.137605Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-5/label/zone-eu=different-value?overwrite=false HTTP/1.1" 200 446 "-" "OpenAPI-Generator/1.0.0/python" 0.002245 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.149773Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-1/pools/node1pool1 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.010733 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.164464Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-2/pools/node2pool1 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.009884 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.176025Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-3/pools/node3pool1 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.009787 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.187976Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-4/pools/node4pool1 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.009537 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.200348Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-5/pools/node5pool1 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.009977 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.226162Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-1/pools/node1pool2 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.023428 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.256654Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-2/pools/node2pool2 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.027960 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.279321Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-3/pools/node3pool2 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.020019 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.300398Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-4/pools/node4pool2 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.018924 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.326016Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-5/pools/node5pool2 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.022987 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.338443Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-1/pools/node1pool3 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.009833 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.349975Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-2/pools/node2pool3 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.008904 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.360013Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-3/pools/node3pool3 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.008247 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.370262Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-4/pools/node4pool3 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.008616 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + 2025-01-02T16:15:20.381486Z  INFO actix_web::middleware::logger: 10.1.0.1 "PUT /v0/nodes/io-engine-5/pools/node5pool3 HTTP/1.1" 200 402 "-" "OpenAPI-Generator/1.0.0/python" 0.009589 + at /home/tiago/.cargo/registry/src/index.crates.io-6f17d22bba15001f/actix-web-4.9.0/src/middleware/logger.rs:424 + + + +Logs for container core: +---------------------------------------- +Control plane agent (core) (debug) revision 740b973c6430 (v2.2.0-rc.1+826) +Using options: CliArgs { cache_period: Duration(30s), reconcile_idle_period: Duration(30s), reconcile_period: Duration(10s), faulted_child_wait_period: None, pool_async_creat_tmo: Duration(900s), disable_partial_rebuild: false, disable_target_acc: false, deadline: Duration(10s), store: "etcd.cluster:2379", store_timeout: Duration(5s), store_lease_ttl: Duration(30s), connect_timeout: Duration(1s), request_timeout: Duration(5s), create_volume_limit: 10, hosts_acl: [Nexuses, Replicas], tracing_tags: [], no_min_timeouts: false, jaeger: Some("jaeger.cluster"), grpc_server_addr: [::]:50051, max_rebuilds: None, thin_args: ThinArgs { pool_commitment: 250, volume_commitment: 40, snapshot_commitment: 40, volume_commitment_initial: 40 }, events_url: None, disable_ha: false, etcd_page_limit: 500, fmt_style: Pretty, ansi_colors: true } + 2025-01-02T16:15:18.800659Z  INFO core::controller::registry: Connecting to persistent store at etcd.cluster:2379 + at control-plane/agents/src/bin/core/controller/registry.rs:141 + + 2025-01-02T16:15:18.802666Z  INFO pstor::etcd_keep_alive: Granted new lease, lease.id: 7587883845849209093, lease.ttl: 30 + at utils/pstor/src/etcd_keep_alive.rs:137 + + 2025-01-02T16:15:18.804082Z  INFO core::controller::registry: Connected to persistent store at etcd.cluster:2379 + at control-plane/agents/src/bin/core/controller/registry.rs:153 + + 2025-01-02T16:15:18.804177Z  INFO pstor::etcd_keep_alive: Locked service with lease, lock.name: CoreAgent, lock.key: /openebs.io/mayastor/apis/v0/clusters/bdd/namespaces/default/StoreLeaseLock/CoreAgent/694d9427ccc45905, lease.id: 7587883845849209093 + at utils/pstor/src/etcd_keep_alive.rs:497 + in pstor::etcd_keep_alive::clock + + 2025-01-02T16:15:18.804785Z  INFO pstor::etcd_keep_alive: Locked => KeepAlive + at utils/pstor/src/etcd_keep_alive.rs:252 + + 2025-01-02T16:15:18.809869Z DEBUG agents: Adding shared type: opentelemetry::global::trace::BoxedTracer + at control-plane/agents/src/lib.rs:139 + + 2025-01-02T16:15:18.809897Z DEBUG agents: Adding shared type: core::controller::registry::Registry + at control-plane/agents/src/lib.rs:139 + + 2025-01-02T16:15:18.809907Z DEBUG agents: Adding shared type: core::net::socket_addr::SocketAddr + at control-plane/agents/src/lib.rs:139 + + 2025-01-02T16:15:18.823104Z  INFO core::controller::reconciler: Starting the reconciler control loop + at control-plane/agents/src/bin/core/controller/reconciler/mod.rs:44 + + 2025-01-02T16:15:19.796398Z DEBUG core::node::wrapper: Creating new node NodeState { id: NodeId("io-engine-3"), grpc_endpoint: 10.1.0.8:10124, status: Online, api_versions: Some([V1]), instance_uuid: Some(51354adf-c69d-4105-a3ef-d5c28638469f), node_nqn: Some(Org { date: "2019-05", domain: "io.openebs", name: "node-name:io-engine-3" }), features: Some(NodeFeatures { asymmetric_namespace_access: Some(true), logical_volume_manager: Some(false), snapshot_rebuild: Some(true), rdma_capable_io_engine: Some(false) }), bugfixes: Some(NodeBugFixes { nexus_rebuild_replica_ancestry: true }), version: Some("v1.0.0-997-g17488f4a7da3") } + at control-plane/agents/src/bin/core/node/wrapper.rs:113 + + 2025-01-02T16:15:19.797582Z  INFO core::node::wrapper: Preloading node, node.id: io-engine-3, node.endpoint: "10.1.0.8:10124", api.versions: Some([V1]), startup: false + at control-plane/agents/src/bin/core/node/wrapper.rs:634 + + 2025-01-02T16:15:19.799889Z DEBUG core::node::watchdog: Arming the node's watchdog, node.id: io-engine-3 + at control-plane/agents/src/bin/core/node/watchdog.rs:39 + + 2025-01-02T16:15:19.829967Z DEBUG core::node::wrapper: Creating new node NodeState { id: NodeId("io-engine-4"), grpc_endpoint: 10.1.0.9:10124, status: Online, api_versions: Some([V1]), instance_uuid: Some(cda2a7f8-9105-43a2-8256-7e03351cd0ae), node_nqn: Some(Org { date: "2019-05", domain: "io.openebs", name: "node-name:io-engine-4" }), features: Some(NodeFeatures { asymmetric_namespace_access: Some(true), logical_volume_manager: Some(false), snapshot_rebuild: Some(true), rdma_capable_io_engine: Some(false) }), bugfixes: Some(NodeBugFixes { nexus_rebuild_replica_ancestry: true }), version: Some("v1.0.0-997-g17488f4a7da3") } + at control-plane/agents/src/bin/core/node/wrapper.rs:113 + + 2025-01-02T16:15:19.830906Z  INFO core::node::wrapper: Preloading node, node.id: io-engine-4, node.endpoint: "10.1.0.9:10124", api.versions: Some([V1]), startup: false + at control-plane/agents/src/bin/core/node/wrapper.rs:634 + + 2025-01-02T16:15:19.832998Z DEBUG core::node::watchdog: Arming the node's watchdog, node.id: io-engine-4 + at control-plane/agents/src/bin/core/node/watchdog.rs:39 + + 2025-01-02T16:15:19.979292Z DEBUG core::node::wrapper: Creating new node NodeState { id: NodeId("io-engine-1"), grpc_endpoint: 10.1.0.6:10124, status: Online, api_versions: Some([V1]), instance_uuid: Some(18d5f98d-3d3b-46f8-8579-a184afcb7558), node_nqn: Some(Org { date: "2019-05", domain: "io.openebs", name: "node-name:io-engine-1" }), features: Some(NodeFeatures { asymmetric_namespace_access: Some(true), logical_volume_manager: Some(false), snapshot_rebuild: Some(true), rdma_capable_io_engine: Some(false) }), bugfixes: Some(NodeBugFixes { nexus_rebuild_replica_ancestry: true }), version: Some("v1.0.0-997-g17488f4a7da3") } + at control-plane/agents/src/bin/core/node/wrapper.rs:113 + + 2025-01-02T16:15:19.980513Z  INFO core::node::wrapper: Preloading node, node.id: io-engine-1, node.endpoint: "10.1.0.6:10124", api.versions: Some([V1]), startup: false + at control-plane/agents/src/bin/core/node/wrapper.rs:634 + + 2025-01-02T16:15:19.981249Z DEBUG core::node::wrapper: Creating new node NodeState { id: NodeId("io-engine-2"), grpc_endpoint: 10.1.0.7:10124, status: Online, api_versions: Some([V1]), instance_uuid: Some(317aec41-1261-46db-a188-fa8d52967243), node_nqn: Some(Org { date: "2019-05", domain: "io.openebs", name: "node-name:io-engine-2" }), features: Some(NodeFeatures { asymmetric_namespace_access: Some(true), logical_volume_manager: Some(false), snapshot_rebuild: Some(true), rdma_capable_io_engine: Some(false) }), bugfixes: Some(NodeBugFixes { nexus_rebuild_replica_ancestry: true }), version: Some("v1.0.0-997-g17488f4a7da3") } + at control-plane/agents/src/bin/core/node/wrapper.rs:113 + + 2025-01-02T16:15:19.982411Z  INFO core::node::wrapper: Preloading node, node.id: io-engine-2, node.endpoint: "10.1.0.7:10124", api.versions: Some([V1]), startup: false + at control-plane/agents/src/bin/core/node/wrapper.rs:634 + + 2025-01-02T16:15:19.983317Z DEBUG core::node::watchdog: Arming the node's watchdog, node.id: io-engine-1 + at control-plane/agents/src/bin/core/node/watchdog.rs:39 + + 2025-01-02T16:15:19.985166Z DEBUG core::node::watchdog: Arming the node's watchdog, node.id: io-engine-2 + at control-plane/agents/src/bin/core/node/watchdog.rs:39 + + 2025-01-02T16:15:20.018283Z DEBUG core::node::wrapper: Creating new node NodeState { id: NodeId("io-engine-5"), grpc_endpoint: 10.1.0.10:10124, status: Online, api_versions: Some([V1]), instance_uuid: Some(3286091e-1d8d-427d-92e9-b61318966c7e), node_nqn: Some(Org { date: "2019-05", domain: "io.openebs", name: "node-name:io-engine-5" }), features: Some(NodeFeatures { asymmetric_namespace_access: Some(true), logical_volume_manager: Some(false), snapshot_rebuild: Some(true), rdma_capable_io_engine: Some(false) }), bugfixes: Some(NodeBugFixes { nexus_rebuild_replica_ancestry: true }), version: Some("v1.0.0-997-g17488f4a7da3") } + at control-plane/agents/src/bin/core/node/wrapper.rs:113 + + 2025-01-02T16:15:20.019362Z  INFO core::node::wrapper: Preloading node, node.id: io-engine-5, node.endpoint: "10.1.0.10:10124", api.versions: Some([V1]), startup: false + at control-plane/agents/src/bin/core/node/wrapper.rs:634 + + 2025-01-02T16:15:20.021783Z DEBUG core::node::watchdog: Arming the node's watchdog, node.id: io-engine-5 + at control-plane/agents/src/bin/core/node/watchdog.rs:39 + + 2025-01-02T16:15:20.101385Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.109207Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.113581Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.117451Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.121383Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.125493Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.129170Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.132838Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.136413Z  INFO core::controller::resources::operations_helper: complete_update, val: () + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:482 + + 2025-01-02T16:15:20.148023Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-1"), id: PoolId("node1pool1"), disks: [PoolDeviceUri("malloc:///node1pool1?size_mb=32&uuid=01a0b44b-13d2-445c-a0ad-e8d53252288e")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-1"), id: PoolId("node1pool1"), disks: [PoolDeviceUri("malloc:///node1pool1?size_mb=32")], labels: Some({"openebs.io/created-by": "operator-diskpool", "node": "io-engine-1"}) }, pool.id: node1pool1 + + 2025-01-02T16:15:20.162846Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-2"), id: PoolId("node2pool1"), disks: [PoolDeviceUri("malloc:///node2pool1?size_mb=32&uuid=3f1d8307-d785-4bbc-8041-8c070b6c628b")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-2"), id: PoolId("node2pool1"), disks: [PoolDeviceUri("malloc:///node2pool1?size_mb=32")], labels: Some({"node": "io-engine-2", "openebs.io/created-by": "operator-diskpool"}) }, pool.id: node2pool1 + + 2025-01-02T16:15:20.174429Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-3"), id: PoolId("node3pool1"), disks: [PoolDeviceUri("malloc:///node3pool1?size_mb=32&uuid=22913e32-d454-4bc0-8a4c-8acfdaeda548")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-3"), id: PoolId("node3pool1"), disks: [PoolDeviceUri("malloc:///node3pool1?size_mb=32")], labels: Some({"openebs.io/created-by": "operator-diskpool", "node": "io-engine-3"}) }, pool.id: node3pool1 + + 2025-01-02T16:15:20.186173Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-4"), id: PoolId("node4pool1"), disks: [PoolDeviceUri("malloc:///node4pool1?size_mb=32&uuid=0d45f56a-811b-4c3b-b380-0b85f02fbd8e")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-4"), id: PoolId("node4pool1"), disks: [PoolDeviceUri("malloc:///node4pool1?size_mb=32")], labels: Some({"openebs.io/created-by": "operator-diskpool", "node": "io-engine-4"}) }, pool.id: node4pool1 + + 2025-01-02T16:15:20.198689Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-5"), id: PoolId("node5pool1"), disks: [PoolDeviceUri("malloc:///node5pool1?size_mb=32&uuid=36988c87-520e-407c-8c61-cbb97bbef13a")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-5"), id: PoolId("node5pool1"), disks: [PoolDeviceUri("malloc:///node5pool1?size_mb=32")], labels: Some({"node": "io-engine-5", "openebs.io/created-by": "operator-diskpool"}) }, pool.id: node5pool1 + + 2025-01-02T16:15:20.224088Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-1"), id: PoolId("node1pool2"), disks: [PoolDeviceUri("malloc:///node1pool2?size_mb=32&uuid=87fc5898-4bbf-4150-b8ea-96b86d83ff87")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-1"), id: PoolId("node1pool2"), disks: [PoolDeviceUri("malloc:///node1pool2?size_mb=32")], labels: Some({"openebs.io/created-by": "operator-diskpool", "node": "io-engine-1"}) }, pool.id: node1pool2 + + 2025-01-02T16:15:20.254668Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-2"), id: PoolId("node2pool2"), disks: [PoolDeviceUri("malloc:///node2pool2?size_mb=32&uuid=6e8a0dd3-7702-4776-9466-fb1815d916f0")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-2"), id: PoolId("node2pool2"), disks: [PoolDeviceUri("malloc:///node2pool2?size_mb=32")], labels: Some({"node": "io-engine-2", "openebs.io/created-by": "operator-diskpool"}) }, pool.id: node2pool2 + + 2025-01-02T16:15:20.277299Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-3"), id: PoolId("node3pool2"), disks: [PoolDeviceUri("malloc:///node3pool2?size_mb=32&uuid=651a4361-673d-40aa-bad6-c2ae77aa4b1d")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-3"), id: PoolId("node3pool2"), disks: [PoolDeviceUri("malloc:///node3pool2?size_mb=32")], labels: Some({"node": "io-engine-3", "openebs.io/created-by": "operator-diskpool"}) }, pool.id: node3pool2 + + 2025-01-02T16:15:20.298290Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-4"), id: PoolId("node4pool2"), disks: [PoolDeviceUri("malloc:///node4pool2?size_mb=32&uuid=2ba5a8c7-eb49-4c9e-9590-206724f63a4e")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-4"), id: PoolId("node4pool2"), disks: [PoolDeviceUri("malloc:///node4pool2?size_mb=32")], labels: Some({"openebs.io/created-by": "operator-diskpool", "node": "io-engine-4"}) }, pool.id: node4pool2 + + 2025-01-02T16:15:20.324258Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-5"), id: PoolId("node5pool2"), disks: [PoolDeviceUri("malloc:///node5pool2?size_mb=32&uuid=bd5e0cb7-6a9f-46bc-bacb-50ac84c8687d")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-5"), id: PoolId("node5pool2"), disks: [PoolDeviceUri("malloc:///node5pool2?size_mb=32")], labels: Some({"node": "io-engine-5", "openebs.io/created-by": "operator-diskpool"}) }, pool.id: node5pool2 + + 2025-01-02T16:15:20.336497Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-1"), id: PoolId("node1pool3"), disks: [PoolDeviceUri("malloc:///node1pool3?size_mb=32&uuid=5455d8f6-0bd1-4e0a-a2cb-c83f96e2fb4d")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-1"), id: PoolId("node1pool3"), disks: [PoolDeviceUri("malloc:///node1pool3?size_mb=32")], labels: Some({"node": "io-engine-1", "openebs.io/created-by": "operator-diskpool"}) }, pool.id: node1pool3 + + 2025-01-02T16:15:20.348299Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-2"), id: PoolId("node2pool3"), disks: [PoolDeviceUri("malloc:///node2pool3?size_mb=32&uuid=5162164a-61a2-492a-9a5e-cd07b758388a")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-2"), id: PoolId("node2pool3"), disks: [PoolDeviceUri("malloc:///node2pool3?size_mb=32")], labels: Some({"node": "io-engine-2", "openebs.io/created-by": "operator-diskpool"}) }, pool.id: node2pool3 + + 2025-01-02T16:15:20.358431Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-3"), id: PoolId("node3pool3"), disks: [PoolDeviceUri("malloc:///node3pool3?size_mb=32&uuid=b2a4eb44-30ea-4935-a58c-adad8acbabd8")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-3"), id: PoolId("node3pool3"), disks: [PoolDeviceUri("malloc:///node3pool3?size_mb=32")], labels: Some({"openebs.io/created-by": "operator-diskpool", "node": "io-engine-3"}) }, pool.id: node3pool3 + + 2025-01-02T16:15:20.368393Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-4"), id: PoolId("node4pool3"), disks: [PoolDeviceUri("malloc:///node4pool3?size_mb=32&uuid=35cab382-e581-4487-957a-e27d49f50029")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-4"), id: PoolId("node4pool3"), disks: [PoolDeviceUri("malloc:///node4pool3?size_mb=32")], labels: Some({"openebs.io/created-by": "operator-diskpool", "node": "io-engine-4"}) }, pool.id: node4pool3 + + 2025-01-02T16:15:20.379621Z  INFO core::controller::resources::operations_helper: complete_create, val: PoolState { node: NodeId("io-engine-5"), id: PoolId("node5pool3"), disks: [PoolDeviceUri("malloc:///node5pool3?size_mb=32&uuid=2fe44623-db41-4e97-b65e-0c9a45c16cd3")], status: Online, capacity: 29360128, used: 0, committed: Some(0) } + at control-plane/agents/src/bin/core/controller/resources/operations_helper.rs:186 + in core::pool::service::create_pool with request: CreatePool { node: NodeId("io-engine-5"), id: PoolId("node5pool3"), disks: [PoolDeviceUri("malloc:///node5pool3?size_mb=32")], labels: Some({"openebs.io/created-by": "operator-diskpool", "node": "io-engine-5"}) }, pool.id: node5pool3 + + + +Logs for container etcd: +---------------------------------------- +{"level":"warn","ts":"2025-01-02T16:15:18.601135Z","caller":"embed/config.go:679","msg":"Running http and grpc server on single port. This is not recommended for production."} +{"level":"info","ts":"2025-01-02T16:15:18.601194Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["/nix/store/7fvflmxl9a8hfznsc1sddp5az1gjlavf-etcd-3.5.13/bin/etcd","--data-dir","/tmp/etcd-data","--advertise-client-urls","http://[::]:2379","--listen-client-urls","http://[::]:2379","--heartbeat-interval=1","--election-timeout=5"]} +{"level":"warn","ts":"2025-01-02T16:15:18.60122Z","caller":"embed/config.go:679","msg":"Running http and grpc server on single port. This is not recommended for production."} +{"level":"info","ts":"2025-01-02T16:15:18.601228Z","caller":"embed/etcd.go:127","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} +{"level":"info","ts":"2025-01-02T16:15:18.601541Z","caller":"embed/etcd.go:135","msg":"configuring client listeners","listen-client-urls":["http://[::]:2379"]} +{"level":"info","ts":"2025-01-02T16:15:18.601625Z","caller":"embed/etcd.go:308","msg":"starting an etcd server","etcd-version":"3.5.13","git-sha":"GitNotFound","go-version":"go1.22.6","go-os":"linux","go-arch":"amd64","max-cpu-set":16,"max-cpu-available":16,"member-initialized":false,"name":"default","data-dir":"/tmp/etcd-data","wal-dir":"","wal-dir-dedicated":"","member-dir":"/tmp/etcd-data/member","force-new-cluster":false,"heartbeat-interval":"1ms","election-timeout":"5ms","initial-election-tick-advance":true,"snapshot-count":100000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://[::]:2379"],"listen-client-urls":["http://[::]:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"default=http://localhost:2380","initial-cluster-state":"new","initial-cluster-token":"etcd-cluster","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"} +{"level":"info","ts":"2025-01-02T16:15:18.601788Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/tmp/etcd-data/member/snap/db","took":"74.082µs"} +{"level":"info","ts":"2025-01-02T16:15:18.616226Z","caller":"etcdserver/raft.go:495","msg":"starting local member","local-member-id":"8e9e05c52164694d","cluster-id":"cdf818194e3a8c32"} +{"level":"info","ts":"2025-01-02T16:15:18.616865Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} +{"level":"info","ts":"2025-01-02T16:15:18.61712Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 0"} +{"level":"info","ts":"2025-01-02T16:15:18.617133Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} +{"level":"info","ts":"2025-01-02T16:15:18.61714Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 1"} +{"level":"info","ts":"2025-01-02T16:15:18.617288Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} +{"level":"warn","ts":"2025-01-02T16:15:18.617509Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} +{"level":"info","ts":"2025-01-02T16:15:18.617646Z","caller":"mvcc/kvstore.go:407","msg":"kvstore restored","current-rev":1} +{"level":"info","ts":"2025-01-02T16:15:18.617699Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} +{"level":"info","ts":"2025-01-02T16:15:18.617755Z","caller":"etcdserver/server.go:867","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.13","cluster-version":"to_be_decided"} +{"level":"info","ts":"2025-01-02T16:15:18.617813Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/tmp/etcd-data/member/snap","suffix":"snap.db","max":5,"interval":"30s"} +{"level":"info","ts":"2025-01-02T16:15:18.617853Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/tmp/etcd-data/member/snap","suffix":"snap","max":5,"interval":"30s"} +{"level":"info","ts":"2025-01-02T16:15:18.617859Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/tmp/etcd-data/member/wal","suffix":"wal","max":5,"interval":"30s"} +{"level":"info","ts":"2025-01-02T16:15:18.617988Z","caller":"etcdserver/server.go:751","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"8e9e05c52164694d","forward-ticks":4,"forward-duration":"4ms","election-ticks":5,"election-timeout":"5ms"} +{"level":"info","ts":"2025-01-02T16:15:18.61829Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} +{"level":"info","ts":"2025-01-02T16:15:18.618375Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","added-peer-id":"8e9e05c52164694d","added-peer-peer-urls":["http://localhost:2380"]} +{"level":"info","ts":"2025-01-02T16:15:18.619476Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 1"} +{"level":"info","ts":"2025-01-02T16:15:18.61951Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 1"} +{"level":"info","ts":"2025-01-02T16:15:18.619528Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 1"} +{"level":"info","ts":"2025-01-02T16:15:18.619539Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 2"} +{"level":"info","ts":"2025-01-02T16:15:18.619546Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 2"} +{"level":"info","ts":"2025-01-02T16:15:18.619563Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 2"} +{"level":"info","ts":"2025-01-02T16:15:18.61957Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 2"} +{"level":"info","ts":"2025-01-02T16:15:18.61976Z","caller":"etcdserver/server.go:2110","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:default ClientURLs:[http://[::]:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"5.01s"} +{"level":"info","ts":"2025-01-02T16:15:18.619845Z","caller":"etcdserver/server.go:2620","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} +{"level":"info","ts":"2025-01-02T16:15:18.619915Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} +{"level":"info","ts":"2025-01-02T16:15:18.619957Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} +{"level":"info","ts":"2025-01-02T16:15:18.619974Z","caller":"etcdserver/server.go:2644","msg":"cluster version is updated","cluster-version":"3.5"} +{"level":"info","ts":"2025-01-02T16:15:18.620056Z","caller":"embed/etcd.go:277","msg":"now serving peer/client/metrics","local-member-id":"8e9e05c52164694d","initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://[::]:2379"],"listen-client-urls":["http://[::]:2379"],"listen-metrics-urls":[]} +{"level":"info","ts":"2025-01-02T16:15:18.620085Z","caller":"embed/etcd.go:597","msg":"serving peer traffic","address":"127.0.0.1:2380"} +{"level":"info","ts":"2025-01-02T16:15:18.620184Z","caller":"embed/etcd.go:569","msg":"cmux::serve","address":"127.0.0.1:2380"} +{"level":"info","ts":"2025-01-02T16:15:18.620099Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} +{"level":"info","ts":"2025-01-02T16:15:18.620473Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} +{"level":"info","ts":"2025-01-02T16:15:18.620486Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} +{"level":"info","ts":"2025-01-02T16:15:18.620844Z","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"[::]:2379"} + + +End of Logs for Test tests/bdd/features/volume/topology/test_node_topology.py::test_suitable_nodes_which_contain_volume_spread_topology_key[True-zone-us-1-<=-succeed-must be-zone-us=us-west-1,zone-us=different-value] (call): +---------------------------------------- + + diff --git a/scripts/python/test.sh b/scripts/python/test.sh index 02c037de2..081cd0437 100755 --- a/scripts/python/test.sh +++ b/scripts/python/test.sh @@ -16,6 +16,7 @@ set -e SCRIPT_DIR="$(dirname "$0")" export ROOT_DIR="$SCRIPT_DIR/../.." REPORT="$ROOT_DIR/report.xml" +export FAILED_DOCKER_LOGS="$ROOT_DIR/docker-logs.txt" cleanup() { "$SCRIPT_DIR"/test-residue-cleanup.sh || true @@ -45,6 +46,7 @@ fi . "$ROOT_DIR"/tests/bdd/setup.sh cleanup >/dev/null +[ -f "$FAILED_DOCKER_LOGS" ] && rm "$FAILED_DOCKER_LOGS" if ! [[ "${DISABLE[*]}" =~ "${CLEAN:-yes}" ]]; then trap cleanup_handler INT QUIT TERM HUP EXIT fi diff --git a/shell.nix b/shell.nix index bc176b407..470a67118 100644 --- a/shell.nix +++ b/shell.nix @@ -40,9 +40,9 @@ mkShell { pre-commit python3 utillinux - rdma-core which paperclip + pytest_inputs ] ++ pkgs.lib.optional (!norust) rust ++ pkgs.lib.optionals (system != "aarch64-darwin") [ e2fsprogs @@ -50,10 +50,10 @@ mkShell { btrfs-progs nvme-cli # python3.9-pyopenssl-22.0.0 marked as broken but fixed on master.. - pytest_inputs tini udev lvm2 + rdma-core ] ++ pkgs.lib.optional (system == "aarch64-darwin") darwin.apple_sdk.frameworks.Security; LIBCLANG_PATH = "${llvmPackages.libclang.lib}/lib"; diff --git a/tests/bdd/common/deployer.py b/tests/bdd/common/deployer.py index e6a597128..a8313205a 100644 --- a/tests/bdd/common/deployer.py +++ b/tests/bdd/common/deployer.py @@ -1,5 +1,6 @@ import os import subprocess +import sys from datetime import datetime import pytest @@ -193,6 +194,8 @@ def start_with_opts(options: StartOptions): @staticmethod def stop(disconnect_nvme=False): print(f"DeployerStop: {datetime.now()}") + if hasattr(sys, "last_traceback") or sys.exc_info()[0] is not None: + Docker.log_containers() clean = os.getenv("CLEAN") if clean is not None and clean.lower() in ("no", "false", "f", "0"): return diff --git a/tests/bdd/common/docker.py b/tests/bdd/common/docker.py index beb566252..75dba8958 100644 --- a/tests/bdd/common/docker.py +++ b/tests/bdd/common/docker.py @@ -1,4 +1,6 @@ +from datetime import datetime import docker +import os class Docker(object): @@ -78,3 +80,22 @@ def restart_container(name): docker_client = docker.from_env() container = docker_client.containers.get(name) container.restart() + + @staticmethod + def log_containers(): + failed_logs_var = "FAILED_DOCKER_LOGS" + if failed_logs_var in os.environ and os.environ[failed_logs_var]: + docker_client = docker.from_env() + current_test = os.environ.get("PYTEST_CURRENT_TEST") + logs = os.environ.get(failed_logs_var) + with open(logs, "a") as log_file: + log_file.write(f"{datetime.now()}: Logs for Test {current_test}:\n") + log_file.write("-" * 40 + "\n\n") + for container in docker_client.containers.list(): + log_file.write(f"Logs for container {container.name}:\n") + log_file.write("-" * 40 + "\n") + logs = container.logs().decode("utf-8") + log_file.write(logs) + log_file.write("\n\n") + log_file.write(f"End of Logs for Test {current_test}:\n") + log_file.write("-" * 40 + "\n\n\n") diff --git a/tests/bdd/features/cordon/node/test_cordon_node.py b/tests/bdd/features/cordon/node/test_cordon-node.py similarity index 100% rename from tests/bdd/features/cordon/node/test_cordon_node.py rename to tests/bdd/features/cordon/node/test_cordon-node.py diff --git a/tests/bdd/features/health_probes/readiness_probe.feature b/tests/bdd/features/health-probes/readiness-probe.feature similarity index 100% rename from tests/bdd/features/health_probes/readiness_probe.feature rename to tests/bdd/features/health-probes/readiness-probe.feature diff --git a/tests/bdd/features/health_probes/test_readiness_probe.py b/tests/bdd/features/health-probes/test_readiness-probe.py similarity index 96% rename from tests/bdd/features/health_probes/test_readiness_probe.py rename to tests/bdd/features/health-probes/test_readiness-probe.py index c7572a006..52fbdd781 100644 --- a/tests/bdd/features/health_probes/test_readiness_probe.py +++ b/tests/bdd/features/health-probes/test_readiness-probe.py @@ -15,15 +15,18 @@ def ready_http_get(context_msg_prefix: str): try: - response = requests.get("http://localhost:8081/ready", timeout=(0.003, 0.010)) + response = requests.get("http://localhost:8081/ready", timeout=(0.3, 0.3)) logger.info( f"{context_msg_prefix}: response.status_code: {response.status_code}" ) return response - except requests.exceptions.Timeout: + except requests.exceptions.Timeout as e: logger.error(f"{context_msg_prefix}: the request timed out") + raise e + except requests.exceptions.RequestException as e: logger.error(f"{context_msg_prefix}: an error occurred: {e}") + raise e @pytest.fixture(scope="module") @@ -34,7 +37,7 @@ def setup(): @scenario( - "readiness_probe.feature", + "readiness-probe.feature", "The REST API /ready service should not update its readiness status more than once in the cache refresh period", ) def test_the_rest_api_ready_service_should_not_update_its_readiness_status_more_than_once_in_the_cache_refresh_period( diff --git a/tests/bdd/features/snapshot/garbage_collection/__init__.py b/tests/bdd/features/snapshot/garbage-collection/__init__.py similarity index 100% rename from tests/bdd/features/snapshot/garbage_collection/__init__.py rename to tests/bdd/features/snapshot/garbage-collection/__init__.py diff --git a/tests/bdd/features/snapshot/garbage_collection/garbage_collection.feature b/tests/bdd/features/snapshot/garbage-collection/garbage-collection.feature similarity index 100% rename from tests/bdd/features/snapshot/garbage_collection/garbage_collection.feature rename to tests/bdd/features/snapshot/garbage-collection/garbage-collection.feature diff --git a/tests/bdd/features/snapshot/garbage_collection/test_garbage_collection.py b/tests/bdd/features/snapshot/garbage-collection/test_garbage-collection.py similarity index 98% rename from tests/bdd/features/snapshot/garbage_collection/test_garbage_collection.py rename to tests/bdd/features/snapshot/garbage-collection/test_garbage-collection.py index 23e1503ba..3ffa7b7d1 100644 --- a/tests/bdd/features/snapshot/garbage_collection/test_garbage_collection.py +++ b/tests/bdd/features/snapshot/garbage-collection/test_garbage-collection.py @@ -25,13 +25,13 @@ SNAP1_UUID = "3f49d30d-a446-4b40-b3f6-f439345f1ce9" -@scenario("garbage_collection.feature", "Garbage collection for failed transactions") +@scenario("garbage-collection.feature", "Garbage collection for failed transactions") def test_garbage_collection_for_failed_transactions(): """Garbage collection for failed transactions.""" @scenario( - "garbage_collection.feature", + "garbage-collection.feature", "Garbage collection for stuck creating snapshots when source is deleted", ) def test_garbage_collection_for_stuck_creating_snapshots_when_source_is_deleted(): diff --git a/tests/bdd/features/volume_group/create/create.feature b/tests/bdd/features/volume-group/create/create.feature similarity index 100% rename from tests/bdd/features/volume_group/create/create.feature rename to tests/bdd/features/volume-group/create/create.feature diff --git a/tests/bdd/features/volume_group/create/test_create.py b/tests/bdd/features/volume-group/create/test_create.py similarity index 100% rename from tests/bdd/features/volume_group/create/test_create.py rename to tests/bdd/features/volume-group/create/test_create.py diff --git a/tests/bdd/features/volume_group/publish/feature.feature b/tests/bdd/features/volume-group/publish/feature.feature similarity index 100% rename from tests/bdd/features/volume_group/publish/feature.feature rename to tests/bdd/features/volume-group/publish/feature.feature diff --git a/tests/bdd/features/volume_group/publish/test_publish.py b/tests/bdd/features/volume-group/publish/test_publish.py similarity index 100% rename from tests/bdd/features/volume_group/publish/test_publish.py rename to tests/bdd/features/volume-group/publish/test_publish.py diff --git a/tests/bdd/features/volume_group/set_replica/feature.feature b/tests/bdd/features/volume-group/set-replica/feature.feature similarity index 100% rename from tests/bdd/features/volume_group/set_replica/feature.feature rename to tests/bdd/features/volume-group/set-replica/feature.feature diff --git a/tests/bdd/features/volume_group/set_replica/test_set_replica.py b/tests/bdd/features/volume-group/set-replica/test_set-replica.py similarity index 100% rename from tests/bdd/features/volume_group/set_replica/test_set_replica.py rename to tests/bdd/features/volume-group/set-replica/test_set-replica.py diff --git a/tests/bdd/features/volume/topology/test_node_topology.py b/tests/bdd/features/volume/topology/test_node-topology.py similarity index 94% rename from tests/bdd/features/volume/topology/test_node_topology.py rename to tests/bdd/features/volume/topology/test_node-topology.py index 345931576..d0e1a65ab 100644 --- a/tests/bdd/features/volume/topology/test_node_topology.py +++ b/tests/bdd/features/volume/topology/test_node-topology.py @@ -82,7 +82,7 @@ "node_name": NODE_1_NAME, "pool_uuid": NODE_1_POOL_1_UUID, "pool_body": CreatePoolBody( - ["malloc:///node1pool1?size_mb=50"], + ["malloc:///node1pool1?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-1", @@ -94,7 +94,7 @@ "node_name": NODE_2_NAME, "pool_uuid": NODE_2_POOL_1_UUID, "pool_body": CreatePoolBody( - ["malloc:///node2pool1?size_mb=50"], + ["malloc:///node2pool1?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-2", @@ -106,7 +106,7 @@ "node_name": NODE_3_NAME, "pool_uuid": NODE_3_POOL_1_UUID, "pool_body": CreatePoolBody( - ["malloc:///node3pool1?size_mb=50"], + ["malloc:///node3pool1?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-3", @@ -118,7 +118,7 @@ "node_name": NODE_4_NAME, "pool_uuid": NODE_4_POOL_1_UUID, "pool_body": CreatePoolBody( - ["malloc:///node4pool1?size_mb=50"], + ["malloc:///node4pool1?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-4", @@ -130,7 +130,7 @@ "node_name": NODE_5_NAME, "pool_uuid": NODE_5_POOL_1_UUID, "pool_body": CreatePoolBody( - ["malloc:///node5pool1?size_mb=50"], + ["malloc:///node5pool1?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-5", @@ -142,7 +142,7 @@ "node_name": NODE_1_NAME, "pool_uuid": NODE_1_POOL_2_UUID, "pool_body": CreatePoolBody( - ["malloc:///node1pool2?size_mb=50"], + ["malloc:///node1pool2?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-1", @@ -154,7 +154,7 @@ "node_name": NODE_2_NAME, "pool_uuid": NODE_2_POOL_2_UUID, "pool_body": CreatePoolBody( - ["malloc:///node2pool2?size_mb=50"], + ["malloc:///node2pool2?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-2", @@ -166,7 +166,7 @@ "node_name": NODE_3_NAME, "pool_uuid": NODE_3_POOL_2_UUID, "pool_body": CreatePoolBody( - ["malloc:///node3pool2?size_mb=50"], + ["malloc:///node3pool2?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-3", @@ -178,7 +178,7 @@ "node_name": NODE_4_NAME, "pool_uuid": NODE_4_POOL_2_UUID, "pool_body": CreatePoolBody( - ["malloc:///node4pool2?size_mb=50"], + ["malloc:///node4pool2?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-4", @@ -190,7 +190,7 @@ "node_name": NODE_5_NAME, "pool_uuid": NODE_5_POOL_2_UUID, "pool_body": CreatePoolBody( - ["malloc:///node5pool2?size_mb=50"], + ["malloc:///node5pool2?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-5", @@ -202,7 +202,7 @@ "node_name": NODE_1_NAME, "pool_uuid": NODE_1_POOL_3_UUID, "pool_body": CreatePoolBody( - ["malloc:///node1pool3?size_mb=50"], + ["malloc:///node1pool3?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-1", @@ -214,7 +214,7 @@ "node_name": NODE_2_NAME, "pool_uuid": NODE_2_POOL_3_UUID, "pool_body": CreatePoolBody( - ["malloc:///node2pool3?size_mb=50"], + ["malloc:///node2pool3?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-2", @@ -226,7 +226,7 @@ "node_name": NODE_3_NAME, "pool_uuid": NODE_3_POOL_3_UUID, "pool_body": CreatePoolBody( - ["malloc:///node3pool3?size_mb=50"], + ["malloc:///node3pool3?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-3", @@ -238,7 +238,7 @@ "node_name": NODE_4_NAME, "pool_uuid": NODE_4_POOL_3_UUID, "pool_body": CreatePoolBody( - ["malloc:///node4pool3?size_mb=50"], + ["malloc:///node4pool3?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-4", @@ -250,7 +250,7 @@ "node_name": NODE_5_NAME, "pool_uuid": NODE_5_POOL_3_UUID, "pool_body": CreatePoolBody( - ["malloc:///node5pool3?size_mb=50"], + ["malloc:///node5pool3?size_mb=32"], labels=disk_pool_label | { "node": "io-engine-5", @@ -275,21 +275,25 @@ @pytest.fixture(scope="module") def init(): Deployer.start(NUM_IO_ENGINES, io_engine_coreisol=True) - # Create the nodes with labels. - for label, node_name in NODE_LABELS: - [key, value] = label.split("=") - ApiClient.nodes_api().put_node_label(node_name, key, value, overwrite="false") - - # Create the pools. - for config in POOL_CONFIGURATIONS: - ApiClient.pools_api().put_node_pool( - config["node_name"], - config["pool_uuid"], - config["pool_body"], - ) - yield - Deployer.stop() + try: + # Create the nodes with labels. + for label, node_name in NODE_LABELS: + [key, value] = label.split("=") + ApiClient.nodes_api().put_node_label( + node_name, key, value, overwrite="false" + ) + + # Create the pools. + for config in POOL_CONFIGURATIONS: + ApiClient.pools_api().put_node_pool( + config["node_name"], + config["pool_uuid"], + config["pool_body"], + ) + yield + finally: + Deployer.stop() # Fixture used to pass the volume create request between test steps. diff --git a/tests/bdd/features/volume/topology/test_pool_topology.py b/tests/bdd/features/volume/topology/test_pool-topology.py similarity index 95% rename from tests/bdd/features/volume/topology/test_pool_topology.py rename to tests/bdd/features/volume/topology/test_pool-topology.py index 6c075000e..095f8d405 100644 --- a/tests/bdd/features/volume/topology/test_pool_topology.py +++ b/tests/bdd/features/volume/topology/test_pool-topology.py @@ -68,7 +68,7 @@ "node_name": NODE_1_NAME, "pool_uuid": NODE_1_POOL_1_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk1?size_mb=50"], + ["malloc:///disk1?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-1", @@ -81,7 +81,7 @@ "node_name": NODE_2_NAME, "pool_uuid": NODE_2_POOL_1_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk1?size_mb=50"], + ["malloc:///disk1?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-2", @@ -94,7 +94,7 @@ "node_name": NODE_3_NAME, "pool_uuid": NODE_3_POOL_1_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk1?size_mb=50"], + ["malloc:///disk1?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-3", @@ -107,7 +107,7 @@ "node_name": NODE_1_NAME, "pool_uuid": NODE_1_POOL_2_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk2?size_mb=50"], + ["malloc:///disk2?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-1", @@ -120,7 +120,7 @@ "node_name": NODE_2_NAME, "pool_uuid": NODE_2_POOL_2_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk2?size_mb=50"], + ["malloc:///disk2?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-2", @@ -133,7 +133,7 @@ "node_name": NODE_3_NAME, "pool_uuid": NODE_3_POOL_2_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk2?size_mb=50"], + ["malloc:///disk2?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-3", @@ -146,7 +146,7 @@ "node_name": NODE_1_NAME, "pool_uuid": NODE_1_POOL_3_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk3?size_mb=50"], + ["malloc:///disk3?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-1", @@ -159,7 +159,7 @@ "node_name": NODE_2_NAME, "pool_uuid": NODE_2_POOL_3_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk3?size_mb=50"], + ["malloc:///disk3?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-2", @@ -172,7 +172,7 @@ "node_name": NODE_3_NAME, "pool_uuid": NODE_3_POOL_3_UUID, "pool_body": CreatePoolBody( - ["malloc:///disk3?size_mb=50"], + ["malloc:///disk3?size_mb=32"], labels={ DISKPOOL_LABEL_KEY: DISKPOOL_LABEL_VAL, "node": "io-engine-3", @@ -186,16 +186,19 @@ @pytest.fixture(scope="module") def init(): Deployer.start(NUM_IO_ENGINES, io_engine_coreisol=True) - # Create the pools. - for config in POOL_CONFIGURATIONS: - ApiClient.pools_api().put_node_pool( - config["node_name"], - config["pool_uuid"], - config["pool_body"], - ) - yield - Deployer.stop() + try: + # Create the pools. + for config in POOL_CONFIGURATIONS: + ApiClient.pools_api().put_node_pool( + config["node_name"], + config["pool_uuid"], + config["pool_body"], + ) + + yield + finally: + Deployer.stop() # Fixture used to pass the volume create request between test steps.