Clone volume failed in parallel

This issue was detected when running CSI E2E testsuite InitProvisioningTestSuite with test case should provision storage with pvc data source in parallel.
To reproduce with k8s e2e framework:
run test suite InitProvisioningTestSuite
To reproduce without k8s e2e framework:
Provision a PVC volume-org with volume mode block.
mount volume volume-org on a pod, as a block device.
in the pod, write some content to this block device.
delete the pod, but leave the PVC untouched.
clone this PVC/volume with 5 replicas at the same time, as volume-0 through volume-4.
mount each clone to a pod, as block device,
verify if all clones have the correct content written before.
Actual Result:
Only the first volume who completed the cloning has the correct content. Other 4 volumes don't have the content. Therefore, test failed.
Expected Result:
All clones have the correct content
Test log please see clone_volume_failed.log
Neonsan CSI controller log:
$ grep pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5 csi-neonsan-controller-94f7df77f-tqz6x_kube-system_csi-neonsan-fe8a350851ce554ba45100c4c3ed1fa00974da6de0c7f3d353c92e6d9a5fce33.log
{"log":"I0930 07:29:25.279549       1 interceptor.go:42] GRPC /csi.v1.Controller/CreateVolume request: {\"capacity_range\":{\"required_bytes\":5368709120},\"name\":\"pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\",\"parameters\":{\"pool_name\":\"kube\",\"rep_count\":\"1\"},\"volume_capabilities\":[{\"AccessType\":{\"Block\":{}},\"access_mode\":{\"mode\":1}}],\"volume_content_source\":{\"Type\":{\"Volume\":{\"volume_id\":\"kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\"}}}} c3ef2b9e\n","stream":"stderr","time":"2020-09-30T07:29:25.282965888Z"}
{"log":"I0930 07:29:25.292800       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=list_volume\u0026pool_name=kube\u0026name=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:25.293015886Z"}
{"log":"I0930 07:29:25.304716       1 api.go:287] NeonsanApi response:{\"op\":\"list_volume_reply\",\"ret_code\":0,\"reason\":\"\",\"count\":0,\"volumes\":[]}, request:http://192.168.0.25:2600/qfa?op=list_volume\u0026pool_name=kube\u0026name=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:25.304933588Z"}
{"log":"I0930 07:29:25.304817       1 controller.go:83] Clone volume pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5 from kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\n","stream":"stderr","time":"2020-09-30T07:29:25.304989942Z"}
{"log":"I0930 07:29:25.347930       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?size=5368709120\u0026rep_count=1\u0026pool_name=kube\u0026rg=demo\u0026encrypte=\u0026op=create_volume\u0026name=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026thick_prov=false\u0026key_name=\u0026\n","stream":"stderr","time":"2020-09-30T07:29:25.348063246Z"}
{"log":"I0930 07:29:25.404572       1 api.go:287] NeonsanApi response:{\"op\":\"create_volume_reply\",\"ret_code\":0,\"reason\":\"\",\"id\":36305895424,\"size\":5368709120}, request:http://192.168.0.25:2600/qfa?size=5368709120\u0026rep_count=1\u0026pool_name=kube\u0026rg=demo\u0026encrypte=\u0026op=create_volume\u0026name=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026thick_prov=false\u0026key_name=\u0026\n","stream":"stderr","time":"2020-09-30T07:29:25.404824178Z"}
{"log":"I0930 07:29:25.413092       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?size=0\u0026op=clone_volume\u0026source_pool=kube\u0026source_vol=pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026snapshot_name=\u0026target_pool=kube\u0026target_vol=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:25.413412051Z"}
{"log":"I0930 07:29:25.503326       1 api.go:287] NeonsanApi response:{\"op\":\"clone_volume_reply\",\"ret_code\":0,\"reason\":\"\",\"id\":\"job0000000141\",\"queue_name\":\"clone_volume_sync\"}, request:http://192.168.0.25:2600/qfa?size=0\u0026op=clone_volume\u0026source_pool=kube\u0026source_vol=pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026snapshot_name=\u0026target_pool=kube\u0026target_vol=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:25.50348482Z"}
{"log":"I0930 07:29:25.513831       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:25.514093047Z"}
{"log":"I0930 07:29:25.537736       1 api.go:287] NeonsanApi response:{\"op\":\"list_clone_reply\",\"ret_code\":0,\"reason\":\"\",\"CloneVolumes\":[{\"id\":424,\"source_vol\":\"kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\",\"target_vol\":\"kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\",\"status\":\"INIT\",\"percent\":0,\"create_time\":\"2020-09-30T15:29:25+08:00\",\"status_time\":\"2020-09-30T15:29:25+08:00\"}]}, request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:25.537950861Z"}
{"log":"I0930 07:29:26.548511       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:26.548772275Z"}
{"log":"I0930 07:29:26.570284       1 api.go:287] NeonsanApi response:{\"op\":\"list_clone_reply\",\"ret_code\":0,\"reason\":\"\",\"CloneVolumes\":[{\"id\":424,\"source_vol\":\"kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\",\"target_vol\":\"kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\",\"status\":\"SYNCING\",\"percent\":0,\"create_time\":\"2020-09-30T15:29:25+08:00\",\"status_time\":\"2020-09-30T15:29:25+08:00\"}]}, request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:26.57046169Z"}
{"log":"I0930 07:29:28.082196       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:28.082424232Z"}
{"log":"I0930 07:29:28.096870       1 api.go:287] NeonsanApi response:{\"op\":\"list_clone_reply\",\"ret_code\":0,\"reason\":\"\",\"CloneVolumes\":[{\"id\":424,\"source_vol\":\"kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\",\"target_vol\":\"kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\",\"status\":\"SYNCING\",\"percent\":0,\"create_time\":\"2020-09-30T15:29:25+08:00\",\"status_time\":\"2020-09-30T15:29:25+08:00\"}]}, request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:28.097031194Z"}
{"log":"I0930 07:29:30.359756       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:30.360003547Z"}
{"log":"I0930 07:29:30.372358       1 api.go:287] NeonsanApi response:{\"op\":\"list_clone_reply\",\"ret_code\":0,\"reason\":\"\",\"CloneVolumes\":[{\"id\":424,\"source_vol\":\"kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\",\"target_vol\":\"kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\",\"status\":\"SYNCING\",\"percent\":0,\"create_time\":\"2020-09-30T15:29:25+08:00\",\"status_time\":\"2020-09-30T15:29:25+08:00\"}]}, request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:30.372485683Z"}
{"log":"I0930 07:29:33.758143       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:33.758379515Z"}
{"log":"I0930 07:29:33.770736       1 api.go:287] NeonsanApi response:{\"op\":\"list_clone_reply\",\"ret_code\":0,\"reason\":\"\",\"CloneVolumes\":[{\"id\":424,\"source_vol\":\"kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\",\"target_vol\":\"kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\",\"status\":\"SYNCED\",\"percent\":100,\"create_time\":\"2020-09-30T15:29:25+08:00\",\"status_time\":\"2020-09-30T15:29:30+08:00\"}]}, request:http://192.168.0.25:2600/qfa?op=list_clone\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:33.770841844Z"}
{"log":"I0930 07:29:33.777782       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=detach_clone_relationship\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:33.777882939Z"}
{"log":"I0930 07:29:33.788839       1 api.go:287] NeonsanApi response:{\"op\":\"detach_clone_relationship_reply\",\"ret_code\":0,\"reason\":\"\",\"CloneRelations\":[{\"SourceVol\":36289118208,\"TargetVol\":36305895424}]}, request:http://192.168.0.25:2600/qfa?op=detach_clone_relationship\u0026source_vol=kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\u0026target_vol=kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:33.788951537Z"}
{"log":"I0930 07:29:33.788982       1 interceptor.go:60] GRPC /csi.v1.Controller/CreateVolume response: {\"volume\":{\"capacity_bytes\":5368709120,\"content_source\":{\"Type\":{\"Volume\":{\"volume_id\":\"kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\"}}},\"volume_context\":{\"pool_name\":\"kube\",\"rep_count\":\"1\"},\"volume_id\":\"kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\"}}  req:{\"capacity_range\":{\"required_bytes\":5368709120},\"name\":\"pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\",\"parameters\":{\"pool_name\":\"kube\",\"rep_count\":\"1\"},\"volume_capabilities\":[{\"AccessType\":{\"Block\":{}},\"access_mode\":{\"mode\":1}}],\"volume_content_source\":{\"Type\":{\"Volume\":{\"volume_id\":\"kube/pvc-520495ef-a1b8-4073-adb4-140e2ef9ed34\"}}}} c3ef2b9e\n","stream":"stderr","time":"2020-09-30T07:29:33.793626364Z"}
{"log":"I0930 07:29:53.569949       1 interceptor.go:42] GRPC /csi.v1.Controller/DeleteVolume request: {\"volume_id\":\"kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\"} d72bafa4\n","stream":"stderr","time":"2020-09-30T07:29:53.570830478Z"}
{"log":"I0930 07:29:53.570755       1 lock.go:45] Try to lock resource kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\n","stream":"stderr","time":"2020-09-30T07:29:53.570864854Z"}
{"log":"I0930 07:29:53.581009       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=list_volume\u0026pool_name=kube\u0026name=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:53.581512644Z"}
{"log":"I0930 07:29:53.593981       1 api.go:287] NeonsanApi response:{\"op\":\"list_volume_reply\",\"ret_code\":0,\"reason\":\"\",\"count\":1,\"volumes\":[{\"id\":36305895424,\"name\":\"pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\",\"pool_name\":\"kube\",\"size\":5368709120,\"replication_count\":1,\"status\":\"OK\",\"min_replication_count\":1,\"role\":\"alone\",\"policy\":\"default\",\"create_time\":\"2020-09-30T15:29:25+08:00\",\"status_time\":\"2020-09-30T15:29:25+08:00\",\"metro_replica\":null,\"provision_type\":\"thin\",\"max_bs\":65536,\"volume_allocated\":0,\"rg_name\":\"demo\",\"encrypted\":\"no\"}]}, request:http://192.168.0.25:2600/qfa?op=list_volume\u0026pool_name=kube\u0026name=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:53.595289399Z"}
{"log":"I0930 07:29:53.614899       1 api.go:268] NeonsanApi request:http://192.168.0.25:2600/qfa?op=delete_volume\u0026pool_name=kube\u0026name=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:53.61499694Z"}
{"log":"I0930 07:29:53.651617       1 api.go:287] NeonsanApi response:{\"op\":\"delete_volume_reply\",\"ret_code\":0,\"reason\":\"\",\"id\":36305895424}, request:http://192.168.0.25:2600/qfa?op=delete_volume\u0026pool_name=kube\u0026name=pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\u0026\n","stream":"stderr","time":"2020-09-30T07:29:53.651782358Z"}
{"log":"I0930 07:29:53.651694       1 interceptor.go:60] GRPC /csi.v1.Controller/DeleteVolume response: {}  req:{\"volume_id\":\"kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\"} d72bafa4\n","stream":"stderr","time":"2020-09-30T07:29:53.653029201Z"}
{"log":"I0930 07:29:53.652857       1 lock.go:59] unlock resource kube/pvc-99cfe5fd-8f1c-45c7-b8f5-b18cee569de5\n","stream":"stderr","time":"2020-09-30T07:29:53.653046717Z"}
Notice the above SYNC_FAILED error, indicated the target volume was not synced with the source volume.
Please investigate why the clone failed, thanks.
Full logs uploaded.
clone_volume_failed.log csi-neonsan-controller-94f7df77f-tqz6x_kube-system_csi-neonsan-fe8a350851ce554ba45100c4c3ed1fa00974da6de0c7f3d353c92e6d9a5fce33.log
yunify / qingstor-csi

Clone volume failed in parallel #45
