search

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
755 stars 109 forks source link

Pool creation should be idempotent #1139

Closed croomes closed 2 years ago

croomes commented 2 years ago

Describe the bug When creating a large pool (4TiB), retries after a timeout eventually return EEXIST: File exists failed to create pool. Instead, the operation should be idempotent and return success..

To Reproduce Steps to reproduce the behavior:

  1. On MSP Operator deployment, set env var RETRIES="50" and --request-timeout=30s
  2. Create MSP: 
    apiVersion: openebs.io/v1alpha1
kind: MayastorPool
   metadata:
name: msp-pool-v9t4n
spec:
  disks:
  - /dev/sde
  node: aks-storagepool-19332723-vmss000002

Expected behavior

Retries work as expected while the pool create operation is in progress. They return: RestJsonError { details: "Conflicts with existing operation - please retry", kind: Conflict } and the MSP Operator will retry.

However, if the create operation completes after the caller timed out, then the next calls will fail.

I believe the code at https://github.com/openebs/mayastor/blob/develop/mayastor/src/lvs/lvs_pool.rs#L432-L437 should be changed to fallthrough and import it (which should also be idempotent).

I'd like to work on this but would appreciate guidance on the approach as I may have missed something.

Logs

[2022-05-25T11:55:25.216814711+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:240] Trying to import pool msp-pool-v9t4n on /dev/sde
[2022-05-25T11:55:25.216838012+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-25T11:55:25.216850012+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-25T11:55:55.220356012+00:00  WARN mayastor::grpc::mayastor_grpc:mayastor_grpc.rs:100] create_pool: gRPC method timed out, args: CreatePoolRequest { name: "msp-pool-v9t4n", disks: ["/dev/sde"] }
[2022-05-25T11:55:55.456536246+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] new
[2022-05-25T11:55:55.456577346+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-25T11:55:55.456618647+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:295] new
[2022-05-25T11:55:55.456632547+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:295] enter
[2022-05-25T11:55:55.456649047+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:240] Trying to import pool msp-pool-v9t4n on /dev/sde
[2022-05-25T11:55:55.456673648+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-25T11:55:55.456686048+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-25T11:56:15.119042033+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-25T11:56:15.119094134+00:00  INFO mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:412] The pool 'msp-pool-v9t4n' has been created on /dev/sde
[2022-05-25T11:56:15.119112934+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-25T11:56:15.119125134+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] close time.busy=66.1ms time.idle=141s
[2022-05-25T11:56:15.119150135+00:00 ERROR mayastor::core::thread:thread.rs:219] Failed to send response future result Ok(Pool { name: "msp-pool-v9t4n", disks: [""], state: PoolOnline, capacity: 4393747349504, used: 0 })
[2022-05-25T11:56:25.459855730+00:00  WARN mayastor::grpc::mayastor_grpc:mayastor_grpc.rs:100] create_pool: gRPC method timed out, args: CreatePoolRequest { name: "msp-pool-v9t4n", disks: ["/dev/sde"] }
[2022-05-25T11:56:25.758600184+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] new
[2022-05-25T11:56:25.758648284+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-25T11:56:25.758686385+00:00 ERROR mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] error=errno: EEXIST: File exists failed to create pool msp-pool-v9t4n
[2022-05-25T11:56:25.758705385+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-v9t4n", disks: ["/dev/sde"], uuid: None }}:lvs_pool.rs:423] exit

OS info (please complete the following information):

Additional context Add any other context about the problem here.

croomes commented 2 years ago

I've had some success making the create pool idempotent, but then the import fails with a similar issue:

[2022-05-26T17:01:24.812350821+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:297] new
[2022-05-26T17:01:24.812361021+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:297] enter
[2022-05-26T17:01:24.812444923+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import{name="msp-pool-q8ts5" bdev="/dev/sdd"}:lvs_pool.rs:238] new
[2022-05-26T17:01:24.812458023+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import{name="msp-pool-q8ts5" bdev="/dev/sdd"}:lvs_pool.rs:238] enter
[2022-05-26T17:01:24.812467723+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import{name="msp-pool-q8ts5" bdev="/dev/sdd"}:lvs_pool.rs:242] Trying to import pool msp-pool-q8ts5 on /dev/sdd
[2022-05-26T17:01:24.812487424+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import{name="msp-pool-q8ts5" bdev="/dev/sdd"}:lvs_pool.rs:238] exit
[2022-05-26T17:01:24.812500524+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:297] exit
[2022-05-26T17:01:24.812511224+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:427] exit
[2022-05-26T17:01:32.810701910+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:427] enter
[2022-05-26T17:01:32.810751611+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:create{name="msp-pool-q8ts5" bdev="/dev/sdd" uuid=None}:lvs_pool.rs:355] enter
[2022-05-26T17:01:32.810855313+00:00  INFO mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:create{name="msp-pool-q8ts5" bdev="/dev/sdd" uuid=None}:lvs_pool.rs:416] The pool 'msp-pool-q8ts5' has been created on /dev/sdd
[2022-05-26T17:01:32.810865613+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:create{name="msp-pool-q8ts5" bdev="/dev/sdd" uuid=None}:lvs_pool.rs:355] return=name: msp-pool-q8ts5, uuid: fb0e8367-9879-4f09-8402-0270cb88b76d, base_bdev: /dev/sdd
[2022-05-26T17:01:32.810877513+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:create{name="msp-pool-q8ts5" bdev="/dev/sdd" uuid=None}:lvs_pool.rs:355] exit
[2022-05-26T17:01:32.810888313+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:create{name="msp-pool-q8ts5" bdev="/dev/sdd" uuid=None}:lvs_pool.rs:355] close time.busy=66.7ms time.idle=129s
[2022-05-26T17:01:32.810905414+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:427] exit
[2022-05-26T17:01:32.810916114+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-q8ts5", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:427] close time.busy=68.0ms time.idle=129s
[2022-05-26T17:01:32.810951814+00:00 ERROR mayastor::core::thread:thread.rs:219] Failed to send response future result Ok(Pool { name: "msp-pool-q8ts5", disks: [""], state: PoolOnline, capacity: 4393747349504, used: 0 })

The pool is online:

/ # mctl -b 10.224.0.7:10124 pool list
NAME           STATE       CAPACITY USED DISKS
msp-pool-q8ts5 online 4393747349504    0

But operator retries don't pick this up, and the MSP status never moves to Online.

NAME             NODE                                  STATUS     CAPACITY   USED   AVAILABLE
msp-pool-q8ts5   aks-storagepool-19332723-vmss000002   Creating   0          0      0
tiagolobocastro commented 2 years ago

Hi @croomes, we might have fixed this already (at least I think @Abhinandan-Purkait seemed to have success with it?) on a feature branch part of a few changes; it should land in develop within a few days

croomes commented 2 years ago

great! Is the branch public?

tiagolobocastro commented 2 years ago 
diff --git a/mayastor/src/grpc/mayastor_grpc.rs b/mayastor/src/grpc/mayastor_grpc.rs
index a087e1fc..2d737ad9 100644
--- a/mayastor/src/grpc/mayastor_grpc.rs
+++ b/mayastor/src/grpc/mayastor_grpc.rs
@@ -385,8 +385,26 @@ impl mayastor_server::Mayastor for MayastorSvc {
                 }

                 let rx = rpc_submit::<_, _, LvsError>(async move {
-                    let pool = Lvs::create_or_import(PoolArgs::try_from(args)?)
-                        .await?;
+                    let pool =
+                        match Lvs::create_or_import(PoolArgs::try_from(args)?)
+                            .await
+                        {
+                            Ok(p) => p,
+                            // this check is added specifically so that the
+                            // create_pool is idempotent
+                            Err(LvsError::PoolCreate {
+                                source,
+                                name,
+                            }) if source == Errno::EEXIST => {
+                                info!(
+                                    "returning already created pool {}",
+                                    name,
+                                );
+                                Lvs::lookup(name.as_str())
+                                    .expect("Already exists")
+                            }
+                            Err(e) => return Err(e),
+                        };
                     // Capture current pool config and export to file.
                     PoolConfig::capture().export().await;
                     Ok(Pool::from(pool))
croomes commented 2 years ago

That worked! :100: 

$ ka get msp -w
NAME             NODE                                  STATUS     CAPACITY   USED   AVAILABLE
msp-pool-sx4kr   aks-storagepool-19332723-vmss000002   Creating   0          0      0
msp-pool-sx4kr   aks-storagepool-19332723-vmss000002   Created    0          0      0
msp-pool-sx4kr   aks-storagepool-19332723-vmss000002   Online     4393747349504   0      4393747349504

Logs in case they're useful:

[2022-05-26T17:52:51.006391114+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] new
[2022-05-26T17:52:51.006435115+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:52:51.006604818+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] new
[2022-05-26T17:52:51.006623518+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] enter
[2022-05-26T17:52:51.006642418+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:240] Trying to import pool msp-pool-sx4kr on /dev/sdd
[2022-05-26T17:52:51.007175028+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-26T17:52:51.007220429+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-26T17:52:51.010603091+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:52:51.010642992+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] enter
[2022-05-26T17:52:51.010663492+00:00 ERROR mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] error=failed to import pool msp-pool-sx4kr
[2022-05-26T17:52:51.010678592+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-26T17:52:51.010691293+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] close time.busy=584µs time.idle=3.50ms
[2022-05-26T17:52:51.081140186+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit

[2022-05-26T17:53:21.008519640+00:00  WARN mayastor::grpc::mayastor_grpc:mayastor_grpc.rs:100] create_pool: gRPC method timed out, args: CreatePoolRequest { name: "msp-pool-sx4kr", disks: ["/dev/sdd"] }
[2022-05-26T17:53:21.295306387+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] new
[2022-05-26T17:53:21.295353988+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:53:21.295404689+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] new
[2022-05-26T17:53:21.295425590+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] enter
[2022-05-26T17:53:21.295444790+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:240] Trying to import pool msp-pool-sx4kr on /dev/sdd
[2022-05-26T17:53:21.295687194+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-26T17:53:21.295709595+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-26T17:53:21.320556849+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:53:21.320602450+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] enter
[2022-05-26T17:53:21.320618750+00:00 ERROR mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] error=failed to import pool msp-pool-sx4kr
[2022-05-26T17:53:21.320635251+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-26T17:53:21.320647251+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] close time.busy=294µs time.idle=24.9ms
[2022-05-26T17:53:21.320727352+00:00 ERROR mayastor::spdk:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvol.c:627] lvolstore with name msp-pool-sx4kr already exists   
[2022-05-26T17:53:21.320752653+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-26T17:53:51.282571178+00:00  WARN mayastor::grpc::mayastor_grpc:mayastor_grpc.rs:100] create_pool: gRPC method timed out, args: CreatePoolRequest { name: "msp-pool-sx4kr", disks: ["/dev/sdd"] }
[2022-05-26T17:53:51.527741157+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] new
[2022-05-26T17:53:51.527782957+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:53:51.527825558+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] new
[2022-05-26T17:53:51.527840058+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] enter
[2022-05-26T17:53:51.527855759+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:240] Trying to import pool msp-pool-sx4kr on /dev/sdd
[2022-05-26T17:53:51.527877959+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-26T17:53:51.527895360+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-26T17:54:21.531056424+00:00  WARN mayastor::grpc::mayastor_grpc:mayastor_grpc.rs:100] create_pool: gRPC method timed out, args: CreatePoolRequest { name: "msp-pool-sx4kr", disks: ["/dev/sdd"] }
[2022-05-26T17:54:21.795451359+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] new
[2022-05-26T17:54:21.795492860+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:54:21.795535760+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] new
[2022-05-26T17:54:21.795549461+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] enter
[2022-05-26T17:54:21.795565961+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:240] Trying to import pool msp-pool-sx4kr on /dev/sdd
[2022-05-26T17:54:21.795589861+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-26T17:54:21.795602462+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-26T17:54:51.797392717+00:00  WARN mayastor::grpc::mayastor_grpc:mayastor_grpc.rs:100] create_pool: gRPC method timed out, args: CreatePoolRequest { name: "msp-pool-sx4kr", disks: ["/dev/sdd"] }
[2022-05-26T17:54:52.062027661+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] new
[2022-05-26T17:54:52.062071162+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:54:52.062114762+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] new
[2022-05-26T17:54:52.062129563+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] enter
[2022-05-26T17:54:52.062145863+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:240] Trying to import pool msp-pool-sx4kr on /dev/sdd
[2022-05-26T17:54:52.062168063+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:import_from_args{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:295] exit
[2022-05-26T17:54:52.062183464+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-26T17:55:00.596862651+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:55:00.596922552+00:00  INFO mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:412] The pool 'msp-pool-sx4kr' has been created on /dev/sdd
[2022-05-26T17:55:00.596941452+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-26T17:55:00.596952953+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] close time.busy=71.4ms time.idle=130s
[2022-05-26T17:55:00.596978853+00:00 ERROR mayastor::core::thread:thread.rs:219] Failed to send response future result Ok(Pool { name: "msp-pool-sx4kr", disks: [""], state: PoolOnline, capacity: 4393747349504, used: 0 })
[2022-05-26T17:55:22.065800343+00:00  WARN mayastor::grpc::mayastor_grpc:mayastor_grpc.rs:100] create_pool: gRPC method timed out, args: CreatePoolRequest { name: "msp-pool-sx4kr", disks: ["/dev/sdd"] }
[2022-05-26T17:55:22.320166791+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] new
[2022-05-26T17:55:22.320217892+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] enter
[2022-05-26T17:55:22.320254193+00:00 ERROR mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] error=errno: EEXIST: File exists failed to create pool msp-pool-sx4kr
[2022-05-26T17:55:22.320278993+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] exit
[2022-05-26T17:55:22.320291193+00:00 DEBUG mayastor::lvs::lvs_pool:create_or_import{args=PoolArgs { name: "msp-pool-sx4kr", disks: ["/dev/sdd"], uuid: None }}:lvs_pool.rs:423] close time.busy=61.4µs time.idle=66.3µs
[2022-05-26T17:55:22.320307294+00:00  INFO mayastor::grpc::mayastor_grpc:mayastor_grpc.rs:399] returning already created pool msp-pool-sx4kr
tiagolobocastro commented 2 years ago

The fix is now in develop, so closing this. Please reopen if you find otherwise.