openebs / mayastor

Dynamically provision Stateful Persistent Replicated Cluster-wide Fabric Volumes & Filesystems for Kubernetes that is provisioned from an optimized NVME SPDK backend data storage stack.
Apache License 2.0
744 stars 106 forks source link

Cannot run test "nexus_add_remove" #1638

Closed MengjinWu closed 5 months ago

MengjinWu commented 6 months ago

I am trying to run the nix-shell --run "./scripts/cargo-test.sh" ci.nix to test for the mayastor. But it always failed in test "nexus_add_remove"

The error output is:

test nexus_add_remove ... [2024-04-16T20:26:54.343210407+08:00  WARN io_engine::core::env:env.rs:670] Increasing debug and print level ...
[2024-04-16T20:26:54.343427870+08:00  INFO io_engine::subsys::config:mod.rs:216] Applying Mayastor configuration settings
[2024-04-16T20:26:54.343457848+08:00 DEBUG io_engine::subsys::config::opts:opts.rs:276] spdk_bdev_nvme_opts { action_on_timeout: 4, timeout_us: 5000000, timeout_admin_us: 5000000, keep_alive_timeout_ms: 1000, 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: false, transport_tos: 0, nvme_error_stat: false, rdma_srq_size: 0, io_path_stat: false }
[2024-04-16T20:26:54.343502874+08:00 DEBUG io_engine::subsys::config:mod.rs:220] Config {
    source: None,
    nvmf_tcp_tgt_conf: NvmfTgtConfig {
        name: "mayastor_target",
        max_namespaces: 2048,
        crdt: 0,
        opts: NvmfTcpTransportOpts {
            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: 2048,
            buf_cache_size: 64,
            dif_insert_or_strip: false,
            abort_timeout_sec: 1,
            acceptor_poll_rate: 10000,
            zcopy: true,
        },
    },
    nvme_bdev_opts: NvmeBdevOpts {
        action_on_timeout: 4,
        timeout_us: 5000000,
        timeout_admin_us: 5000000,
        keep_alive_timeout_ms: 1000,
        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,
        async_mode: false,
    },
    bdev_opts: BdevOpts {
        bdev_io_pool_size: 65535,
        bdev_io_cache_size: 512,
        small_buf_pool_size: 8191,
        large_buf_pool_size: 1023,
    },
    nexus_opts: NexusOpts {
        nvmf_enable: true,
        nvmf_discovery_enable: true,
        nvmf_nexus_port: 4421,
        nvmf_replica_port: 8420,
    },
}
[2024-04-16T20:26:54.343591189+08:00 DEBUG io_engine::core::env:env.rs:650] EAL arguments ["mayastor", "--no-shconf", "-m 0", "--no-pci", "--base-virtaddr=0x200000000000", "--file-prefix=mayastor_pid961007", "--huge-unlink", "--log-level=lib.eal:6", "--log-level=lib.cryptodev:5", "--log-level=user1:6", "--match-allocations", "-c 0x3"]
[2024-04-16T20:26:55.098734422+08:00  INFO io_engine::core::mempool:mempool.rs:50] Memory pool 'bdev_io_ctx' with 65535 elements (80 bytes size) successfully created
[2024-04-16T20:26:55.818248420+08:00  INFO io_engine::core::mempool:mempool.rs:50] Memory pool 'nvme_ctrl_io_ctx' with 65535 elements (128 bytes size) successfully created
[2024-04-16T20:26:55.818465207+08:00  INFO io_engine::core::env:env.rs:873] Total number of cores available: 2
[2024-04-16T20:26:56.782504311+08:00  INFO io_engine::core::reactor:reactor.rs:182] Scheduled SPDK thread 'init_thread' (0x7fc26805b2d0) on core #0
[2024-04-16T20:26:56.782673245+08:00  INFO io_engine::core::reactor:reactor.rs:158] Init thread ID 1
[2024-04-16T20:26:56.782770340+08:00  INFO io_engine::core::reactor:reactor.rs:301] Starting reactor polling loop core=1 tid=961449
[2024-04-16T20:26:56.787025540+08:00  INFO io_engine::core::env:env.rs:902] All cores locked and loaded!
[2024-04-16T20:26:56.831892647+08:00 DEBUG io_engine::subsys::config:mod.rs:58] mayastor subsystem init
[2024-04-16T20:26:56.876668031+08:00  INFO io_engine::bdev::nexus::nexus_module:nexus_module.rs:36] Initializing Nexus CAS Module
[2024-04-16T20:26:56.876798753+08:00 DEBUG io_engine::subsys::nvmf:mod.rs:97] NVMF subsystem init
[2024-04-16T20:26:56.876914114+08:00  INFO io_engine::core::reactor:reactor.rs:182] Scheduled SPDK thread 'mayastor_nvmf_tcp_pg_core_0' (0x7fc268060da0) on core #0
[2024-04-16T20:26:56.876985039+08:00  INFO io_engine::core::reactor:reactor.rs:182] Scheduled SPDK thread 'mayastor_nvmf_tcp_pg_core_1' (0x7fc2680613f0) on core #1
[2024-04-16T20:26:56.895210404+08:00  INFO mayastor::spdk:tcp.c:631] *** TCP Transport Init ***
  Transport opts:  max_ioq_depth=32, max_io_size=131072,
  max_io_qpairs_per_ctrlr=31, io_unit_size=131072,
  in_capsule_data_size=4096, max_aq_depth=32
  num_shared_buffers=2048, c2h_success=1,
  dif_insert_or_strip=0, sock_priority=0
  abort_timeout_sec=1, control_msg_num=32   
[2024-04-16T20:26:56.985415362+08:00 DEBUG io_engine::subsys::nvmf::transport:transport.rs:61] Added TCP nvmf transport
[2024-04-16T20:26:56.985669237+08:00  INFO io_engine::subsys::nvmf::target:target.rs:263] nvmf target listening on 127.0.0.1:(4421,8420)
[2024-04-16T20:26:56.985705372+08:00 DEBUG io_engine::subsys::nvmf::target:target.rs:276] enabling discovery for target
[2024-04-16T20:26:56.985806223+08:00  INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:819] 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: 1, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "127.0.0.1", trsvcid: "8420" }]) }
[2024-04-16T20:26:56.985905169+08:00  INFO io_engine::subsys::nvmf::subsystem:subsystem.rs:870] 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: 1, ana_reporting: 0, listeners: Some([Transport ID { trtype: 3, trstring: "TCP", traddr: "127.0.0.1", trsvcid: "8420" }]) }
[2024-04-16T20:26:56.985962642+08:00  INFO io_engine::subsys::nvmf::target:target.rs:359] nvmf target accepting new connections and is ready to roll..💃
[2024-04-16T20:26:57.183548842+08:00  INFO io_engine::core::reactor:reactor.rs:182] Scheduled SPDK thread 'iscsi_poll_group_0' (0x7fc2681f2980) on core #0
[2024-04-16T20:26:57.183997484+08:00  INFO io_engine::core::reactor:reactor.rs:182] Scheduled SPDK thread 'iscsi_poll_group_1' (0x7fc2681f2cd0) on core #1
[2024-04-16T20:26:57.184144833+08:00  INFO io_engine::core::env:env.rs:802] RPC server listening at: /var/tmp/mayastor.sock
FAILED

failures:

---- nexus_add_remove stdout ----
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: "Failed to connect to ms1/10.1.0.2:10124"', io-engine/tests/nexus_add_remove.rs:206:46

What should I do to make it run properly?

tiagolobocastro commented 6 months ago

Anything you can get from the container logs ms1,ms2,ms3 ?

tiagolobocastro commented 5 months ago

Probably related to #1640 Please reopen if otherwise