Bug 1879057

Created attachment 1714912 [details]
manifest.yaml

Here is the test result for NFS and gluster driver https://testgrid.k8s.io/sig-storage-kubernetes#gce-slow

not sure it's a CSI driver issue or certificate test case issue
@Fabio @Niels @Madhu could you please kindly take a look?

I am able to reproduce this when running only the failing test against OCS-4.5 on AWS.

As this is for (In reply to Yan Du from comment #2)
> Here is the test result for NFS and gluster driver
> https://testgrid.k8s.io/sig-storage-kubernetes#gce-slow

This statement might not be relevant, NFS does not support blockmode, and I am not sure the linked tests contain Gluster with block mode either. If you search for

    Testpattern: Dynamic PV (block volmode)

in the output, the test is run for only a few drivers. And only "gcepd" seems to run

    multiVolume [Slow] should concurrently access the single read-only volume from pods on the same node


As the writes done are small, I wonder if these are cached. The command that writes:

    ... | dd of=/mnt/volume1 bs=64 count=1

And the command that reads:

    dd if=/mnt/volume1 bs=64 count=1 | ...

None of these commands contain "conv=fdatasync", "iflag=direct" / "oflag=direct" or similar. Adding synchronisation/flushing might make the tests more solid, and have them pass on other storage backends.

Created attachment 1715094 [details]
Proposed patch to disable caching in the test-case

Attaching a patch for the test-case that fails. This change disables caching when running the "dd" commands, both for writing and reading.

[Now I need to figure out how to build and run the modified tests...]

I tried the patch from comment #4; but unfortunately I got the same error.

I modified the test to preserve the NS and the pods in it, so I could take a look after the test failure. 

I noticed that whatever I wrote to the block device from pod A, pod B would never see the changes. As if both pods wouldn't be sharing the same block volume.

Steps:

1. Both pods are using the same volume:

[cnv-qe-jenkins@yadu-ocs-69f6t-executor csi-tests]$ oc -n e2e-multivolume-53 get pods 
NAME                                       READY   STATUS    RESTARTS   AGE
pod-1bc782d8-2a2a-4060-bf44-adda4279b064   1/1     Running   0          41m
pod-830e9f7a-bfd6-48bc-8f7d-b0e8395aebc8   1/1     Running   0          41m

[cnv-qe-jenkins@yadu-ocs-69f6t-executor csi-tests]$ oc -n e2e-multivolume-53 get pod/pod-1bc782d8-2a2a-4060-bf44-adda4279b064 -o json | jq .spec.volumes
[
  {
    "name": "volume1",
    "persistentVolumeClaim": {
      "claimName": "openshift-storage.rbd.csi.ceph.com5j4sd"
    }
  },
  {
    "name": "default-token-lr4pj",
    "secret": {
      "defaultMode": 420,
      "secretName": "default-token-lr4pj"
    }
  }
]

[cnv-qe-jenkins@yadu-ocs-69f6t-executor csi-tests]$ oc -n e2e-multivolume-53 get pod/pod-830e9f7a-bfd6-48bc-8f7d-b0e8395aebc8 -o json | jq .spec.volumes
[
  {
    "name": "volume1",
    "persistentVolumeClaim": {
      "claimName": "openshift-storage.rbd.csi.ceph.com5j4sd"
    }
  },
  {
    "name": "default-token-lr4pj",
    "secret": {
      "defaultMode": 420,
      "secretName": "default-token-lr4pj"
    }
  }
]

VolNode is block and access mode is RWX:

[cnv-qe-jenkins@yadu-ocs-69f6t-executor csi-tests]$ oc -n $(oc get ns | grep multivolume | awk '{print $1}') get pvc/openshift-storage.rbd.csi.ceph.com5j4sd -o json
(...)
  "spec": {
    "accessModes": [
      "ReadWriteMany"
    ],
    "resources": {
      "requests": {
        "storage": "1Gi"
      }
    },
    "storageClassName": "e2e-multivolume-53-e2e-sc2q5lz",
    "volumeMode": "Block",
    "volumeName": "pvc-f350fd53-4b93-4ed1-b054-1d19d454fdf8"
  },
  "status": {
    "accessModes": [
      "ReadWriteMany"
    ],
    "capacity": {
      "storage": "1Gi"
    },
    "phase": "Bound"
  }
}


In one of the pods that are using the volume, I wrote some random data to /mnt/volume1 and checked the sha256sum:

/ # dd if=/dev/random of=/mnt/volume1 bs=512MB count=2                                                                 │
0+2 records in                                                                                                         │
0+2 records out                                                                                                        │
16 bytes (16B) copied, 11.922763 seconds, 1B/s                                                                         │
/ # dd if=/mnt/volume1 bs=512MB count=2 2> /dev/null | sha256sum
77822593f1477b381d11d0798e7c93c80502b418d0ea66a7e925591163f402bd  -

Then in the other pod I checked the sha256sum and I got a different one:

/ # dd if=/mnt/volume1 bs=512MB count=2 2> /dev/null | sha256sum 
837d0431ea5e77fa6c2b36c71d84743b35768432ca56f1872352a04e0e8819ff

Both pods were using busybox as base image (because that's what the upstream e2e tests use).

The next step would be to manually create 2 pods sharing the same RWX volume and repeat the steps above.

1. I manually created 2 pods sharing a RBD block volume with access mode RWX
2. From pod A, wrote 1G of random data to /mnt/volume1, sync'ed, and calculated the sha256sum of it
3. From pod B, calculated the sha256sum of the block volume and got the same result

However, both pod A and B were scheduled on the same node.

When I repeated the experiment with pods scheduled on different nodes, the sha256sums of the volumes were different.

When running pods on the same node, the same RBD block device is used (bind mounted in two containers), so that works without issues.

When running pods on two different nodes, difference RBD block devices (kernel view) are used, so caches are disconnected as well. The following yaml can be used to reproduce the behaviour:

=== %< === :: update the nodeName to whatever workers you want to use
---
apiVersion: v1
kind: PersistentVolumeClaim
metadata:
  name: bz1879057-data
spec:
  accessModes:
    - ReadWriteMany
  volumeMode: Block
  resources:
    requests:
      storage: 1Gi
  storageClassName: ocs-storagecluster-ceph-rbd
---
apiVersion: v1
kind: Pod
metadata:
  name: bz1879057-writer
spec:
  containers:
    - name: centos
      image: centos:latest
      command: ["/bin/sleep", "infinity"]
      volumeDevices:
        - name: data
          devicePath: /dev/xvda
  volumes:
    - name: data
      persistentVolumeClaim:
        claimName: bz1879057-data
  nodeName: ip-10-0-154-198.ec2.internal
---
apiVersion: v1
kind: Pod
metadata:
  name: bz1879057-reader
spec:
  containers:
    - name: centos
      image: centos:latest
      command: ["/bin/sleep", "infinity"]
      volumeDevices:
        - name: data
          devicePath: /dev/xvda
  volumes:
    - name: data
      persistentVolumeClaim:
        claimName: bz1879057-data
  nodeName: ip-10-0-134-231.ec2.internal

=== %< ===

Write some data:

$ oc rsh bz1879057-writer
sh-4.4# dd if=/dev/random of=/dev/xvda bs=4096 count=1
0+1 records in
0+1 records out
115 bytes copied, 7.1618e-05 s, 1.6 MB/s
sh-4.4# dd if=/dev/xvda bs=4096 count=1 | sha256sum
1+0 records in
1+0 records out
4096 bytes (4.1 kB, 4.0 KiB) copied, 4.4295e-05 s, 92.5 MB/s
7a9c2d3abb28b436c42b8d01c41e005302e95705066379294c0f6f9db315a06c  -

Read the data:

$ oc rsh bz1879057-reader
sh-4.4# dd if=/dev/xvda bs=4096 count=1 iflag=direct | sha256sum 
1+0 records in
1+0 records out
4096 bytes (4.1 kB, 4.0 KiB) copied, 0.000971202 s, 4.2 MB/s
7a9c2d3abb28b436c42b8d01c41e005302e95705066379294c0f6f9db315a06c  -


Without "iflag=direct" on the reader, some caching is used and reads do not reach the device.

NOTE: a blocksize of 4096 bytes is used, it is a requirement for reading a full block woth direct-io.

(In reply to Niels de Vos from comment #8)
> NOTE: a blocksize of 4096 bytes is used, it is a requirement for reading a
> full block woth direct-io.

Correction, 4096 is not the blocksize of the device, but 512 bytes is. So everything works with "bs=512" too.

Created attachment 1715235 [details]
Proposed patch to disable caching in the test-case

Updated the patch to disable caching for shared block device tests:

By passing "oflag=nocache" and "iflag=direct", caching should be
disabled while writing/reading with "dd" to a block device. The
TestConcurrentAccessToSingleVolume() test is known to fail with certain
storage backends (like Ceph RBD) when caching is enabled.

The default BusyBox image used for testing does not support the required
options for "dd". So instead of running with BusyBox, run the test with
a CentOS-8 image.

Created attachment 1715239 [details]
Proposed patch to disable caching in the test-case

Fabio reported that the dd command to write is incorrect. Updated the patch so it can get tested again.

Sorry for the troubles!

Upstream issue: https://github.com/kubernetes/kubernetes/issues/94882
Upstream patch submitted by @Niels: https://github.com/kubernetes/kubernetes/pull/94881

Backports for OpenShift have been posted:
- https://github.com/openshift/kubernetes/pull/378
- https://github.com/openshift/origin/pull/25566

Verified with: 4.7.0-0.nightly-2020-10-17-034503

[piqin@preserve-storage-server1 rbd]$ docker run -v `pwd`:/data:z --entrypoint /bin/sh --rm -it quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:fec587d70ce2ba99e0055587531b0f77406a2b4111eff8ebdcc059506d5b9f92
sh-4.4# export KUBECONFIG=/data/kubeconfig
sh-4.4# export TEST_CSI_DRIVER_FILES=/data/manifest.yaml
sh-4.4# openshift-tests run --dry-run openshift/csi|grep "\[Testpattern\: Dynamic PV (block volmode)\] multiVolume \[Slow\] should concurrently access the single volume from pods on different node"|openshift-tests  run -f -
openshift-tests version: v4.1.0-3275-g0648c934c5
I1020 08:07:16.093210      11 test_context.go:429] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready
I1020 08:07:16.269924      13 test_context.go:429] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready
started: (0/1/1) "External Storage [Driver: openshift-storage.rbd.csi.ceph.com] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] should concurrently access the single volume from pods on different node"

I1020 08:07:16.929450      33 test_context.go:429] Tolerating taints "node-role.kubernetes.io/master" when considering if nodes are ready
Oct 20 08:07:17.028: INFO: Waiting up to 30m0s for all (but 100) nodes to be schedulable
Oct 20 08:07:17.170: INFO: Waiting up to 10m0s for all pods (need at least 0) in namespace 'kube-system' to be running and ready
Oct 20 08:07:17.263: INFO: 0 / 0 pods in namespace 'kube-system' are running and ready (0 seconds elapsed)
Oct 20 08:07:17.263: INFO: expected 0 pod replicas in namespace 'kube-system', 0 are Running and Ready.
Oct 20 08:07:17.263: INFO: Waiting up to 5m0s for all daemonsets in namespace 'kube-system' to start
Oct 20 08:07:17.292: INFO: e2e test version: v0.0.0-master+$Format:%h$
Oct 20 08:07:17.312: INFO: kube-apiserver version: v1.19.0+0c1205c
Oct 20 08:07:17.338: INFO: Cluster IP family: ipv4
[BeforeEach] [Top Level]
  github.com/openshift/origin/test/extended/util/framework.go:1429
[BeforeEach] [Top Level]
  github.com/openshift/origin/test/extended/util/framework.go:1429
[BeforeEach] [Top Level]
  github.com/openshift/origin/test/extended/util/test.go:59
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  k8s.io/kubernetes.0/test/e2e/storage/testsuites/base.go:127
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  k8s.io/kubernetes.0/test/e2e/storage/testsuites/multivolume.go:90
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  k8s.io/kubernetes.0/test/e2e/framework/framework.go:174
STEP: Creating a kubernetes client
STEP: Building a namespace api object, basename multivolume
Oct 20 08:07:17.419: INFO: About to run a Kube e2e test, ensuring namespace is privileged
Oct 20 08:07:17.688: INFO: No PodSecurityPolicies found; assuming PodSecurityPolicy is disabled.
STEP: Waiting for a default service account to be provisioned in namespace
[It] should concurrently access the single volume from pods on different node
  k8s.io/kubernetes.0/test/e2e/storage/testsuites/multivolume.go:362
Oct 20 08:07:17.754: INFO: Creating resource for dynamic PV
Oct 20 08:07:17.754: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(openshift-storage.rbd.csi.ceph.com) supported size:{ 1Mi} 
STEP: creating a StorageClass e2e-multivolume-5099-e2e-scprdtq
STEP: creating a claim
Oct 20 08:07:17.805: INFO: Waiting up to 5m0s for PersistentVolumeClaims [openshift-storage.rbd.csi.ceph.comxsp5q] to have phase Bound
Oct 20 08:07:17.829: INFO: PersistentVolumeClaim openshift-storage.rbd.csi.ceph.comxsp5q found but phase is Pending instead of Bound.
Oct 20 08:07:19.851: INFO: PersistentVolumeClaim openshift-storage.rbd.csi.ceph.comxsp5q found and phase=Bound (2.045221613s)
STEP: Creating pod1 with a volume on {Name: Selector:map[] Affinity:nil}
STEP: Creating pod2 with a volume on {Name: Selector:map[] Affinity:&Affinity{NodeAffinity:&NodeAffinity{RequiredDuringSchedulingIgnoredDuringExecution:&NodeSelector{NodeSelectorTerms:[]NodeSelectorTerm{NodeSelectorTerm{MatchExpressions:[]NodeSelectorRequirement{},MatchFields:[]NodeSelectorRequirement{NodeSelectorRequirement{Key:metadata.name,Operator:NotIn,Values:[ip-10-0-138-227.us-east-2.compute.internal],},},},},},PreferredDuringSchedulingIgnoredDuringExecution:[]PreferredSchedulingTerm{},},PodAffinity:nil,PodAntiAffinity:nil,}}
STEP: Checking if the volume in pod1 exists as expected volume mode (Block)
Oct 20 08:07:46.157: INFO: ExecWithOptions {Command:[/bin/sh -c test -b /mnt/volume1] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:07:46.381: INFO: ExecWithOptions {Command:[/bin/sh -c test -d /mnt/volume1] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: Checking if write to the volume in pod1 works properly
Oct 20 08:07:46.609: INFO: ExecWithOptions {Command:[/bin/sh -c echo XKA01Kf2dfgXOVT+6HvnEoY4zxP5wPMUm/e6Idml2ELcb9UkV96CNbPEslRLQ4I5gxFJgfREVWQ/VoE+U7m4Wvr5i9AHYe0BBUHS0aaaBgJsfHF5hmGXuDSlq/H54uCOOXpY3GDCa/bIR2VbqoV3DbyuDF1fRa67csUqFtNXjGf6wyVJoOJTjCXgfMYTaqKB16vjzQHublkANAQsY8IjrP1OFwNBN7SrSw2iJZw52no9olkmLFAiYelfhcZlQaYzz30VucBz+YH/qMBa+qAWMaFahxRGpWuQr76r8AEcAe1mh7wTC2pYiekka8KD2iPBwu4e7T1gsTFgd6OQ7LAJ6mCEIxVqcGFO6nB5jgQcr+OUkJMgaUk0hbVxy/N59lpj6CBnr/VD6+D5qJ/3HkR21HWcPUbDayGqGMpk+hlHlBvgrVhX5tJOQOr1gp1+49LEQGOw735Aupt/6ExOpps3ti1Vm365Sgnfpx6g4k3Mny36Y7wE4/emuUT4NXu9VuByBKA86fIstnhpCT1S7zy13WQc5CefCI9TIDyOLNbUedMIIvxQYfFt+9yZVl5ncXekAmQo0JFs9PLmVBBjIYSM2Bjw5N7is/s6bzXznXBnec5wqBBT/VDPC99Dv9aEj4KJr/Txm3OUptr6p4EeA9cFa6H3ZjbaTqw1eF+8xyy6sGw= | base64 -d | sha256sum] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:07:46.837: INFO: ExecWithOptions {Command:[/bin/sh -c echo XKA01Kf2dfgXOVT+6HvnEoY4zxP5wPMUm/e6Idml2ELcb9UkV96CNbPEslRLQ4I5gxFJgfREVWQ/VoE+U7m4Wvr5i9AHYe0BBUHS0aaaBgJsfHF5hmGXuDSlq/H54uCOOXpY3GDCa/bIR2VbqoV3DbyuDF1fRa67csUqFtNXjGf6wyVJoOJTjCXgfMYTaqKB16vjzQHublkANAQsY8IjrP1OFwNBN7SrSw2iJZw52no9olkmLFAiYelfhcZlQaYzz30VucBz+YH/qMBa+qAWMaFahxRGpWuQr76r8AEcAe1mh7wTC2pYiekka8KD2iPBwu4e7T1gsTFgd6OQ7LAJ6mCEIxVqcGFO6nB5jgQcr+OUkJMgaUk0hbVxy/N59lpj6CBnr/VD6+D5qJ/3HkR21HWcPUbDayGqGMpk+hlHlBvgrVhX5tJOQOr1gp1+49LEQGOw735Aupt/6ExOpps3ti1Vm365Sgnfpx6g4k3Mny36Y7wE4/emuUT4NXu9VuByBKA86fIstnhpCT1S7zy13WQc5CefCI9TIDyOLNbUedMIIvxQYfFt+9yZVl5ncXekAmQo0JFs9PLmVBBjIYSM2Bjw5N7is/s6bzXznXBnec5wqBBT/VDPC99Dv9aEj4KJr/Txm3OUptr6p4EeA9cFa6H3ZjbaTqw1eF+8xyy6sGw= | base64 -d | dd of=/mnt/volume1 oflag=nocache bs=512 count=1] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: Checking if read from the volume in pod1 works properly
Oct 20 08:07:47.041: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:07:47.257: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum | grep -Fq fc29760cb786ede241c67165d135486cc8ad7afa86977330abc8ca796608bd32] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: Checking if the volume in pod2 exists as expected volume mode (Block)
Oct 20 08:07:47.487: INFO: ExecWithOptions {Command:[/bin/sh -c test -b /mnt/volume1] Namespace:e2e-multivolume-5099 PodName:pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:07:47.699: INFO: ExecWithOptions {Command:[/bin/sh -c test -d /mnt/volume1] Namespace:e2e-multivolume-5099 PodName:pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: From pod2, checking if reading the data that pod1 write works properly
Oct 20 08:07:47.915: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum] Namespace:e2e-multivolume-5099 PodName:pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:07:48.121: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum | grep -Fq fc29760cb786ede241c67165d135486cc8ad7afa86977330abc8ca796608bd32] Namespace:e2e-multivolume-5099 PodName:pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: Checking if write to the volume in pod2 works properly
Oct 20 08:07:48.339: INFO: ExecWithOptions {Command:[/bin/sh -c echo h3CoTd6UhXYoJCujZdhy+bK5BFdByDqw6WoT8tdO0wrMaK9xbV1l5sfxz8VpgXc1JWqoq/tEtkgqEZ56OKsoqHRoXGP9Rg+VJf7b/v2GAGGKsVnJvY2VYB62RYLGUFX9lOG0ZqLtwIwTpVZCk/AbjDZws6NIaAYBbpkN20bTEXCi6wGEBtCFqjoqfiN4sRN78NR6S43pGu7MrKCeRdu6go2+3hvu2geBAEp4gAMnzjDI2aefVU/Mc8uBlhGpyJJoIA6+IRywRiVptvrlXqraJI4Uied8orA54rLYxUBldOQJjmfkD9r91bHYdIP7jFu/HLSQlYxLClDcpIANptKYDSOvAewjMa5UEpb5O/+BUIwp8y/8PysUN/gaTRdlnf2O3WfUBxgmUSwRrm67z5rh/EGFbec9Lk9nOua/cwOJl5QgF9Jy8id2TbZSjuwgn4McK2quoCv1G0QZRMFENyFmbDU48H/IsPxAw6h5wxJ0zsqSW4ATHol9ZEUKl9qDplaZcts/bRAnwqnV+Yiur48p8Ji7cUP1jCPZIGqngeW3w5FC9nFoSJJ4jqJY9r8TGF8+GH1bAhxI3D0sF+Wnhv+33FULNDXGKpYPAv/T3VIRdbBYvbqLZ79o5qWBhVDIazTjGIqdYO5+Vtgzwlcs151Bescp7bVHqCIhw1e5sPeWSu0= | base64 -d | sha256sum] Namespace:e2e-multivolume-5099 PodName:pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:07:48.553: INFO: ExecWithOptions {Command:[/bin/sh -c echo h3CoTd6UhXYoJCujZdhy+bK5BFdByDqw6WoT8tdO0wrMaK9xbV1l5sfxz8VpgXc1JWqoq/tEtkgqEZ56OKsoqHRoXGP9Rg+VJf7b/v2GAGGKsVnJvY2VYB62RYLGUFX9lOG0ZqLtwIwTpVZCk/AbjDZws6NIaAYBbpkN20bTEXCi6wGEBtCFqjoqfiN4sRN78NR6S43pGu7MrKCeRdu6go2+3hvu2geBAEp4gAMnzjDI2aefVU/Mc8uBlhGpyJJoIA6+IRywRiVptvrlXqraJI4Uied8orA54rLYxUBldOQJjmfkD9r91bHYdIP7jFu/HLSQlYxLClDcpIANptKYDSOvAewjMa5UEpb5O/+BUIwp8y/8PysUN/gaTRdlnf2O3WfUBxgmUSwRrm67z5rh/EGFbec9Lk9nOua/cwOJl5QgF9Jy8id2TbZSjuwgn4McK2quoCv1G0QZRMFENyFmbDU48H/IsPxAw6h5wxJ0zsqSW4ATHol9ZEUKl9qDplaZcts/bRAnwqnV+Yiur48p8Ji7cUP1jCPZIGqngeW3w5FC9nFoSJJ4jqJY9r8TGF8+GH1bAhxI3D0sF+Wnhv+33FULNDXGKpYPAv/T3VIRdbBYvbqLZ79o5qWBhVDIazTjGIqdYO5+Vtgzwlcs151Bescp7bVHqCIhw1e5sPeWSu0= | base64 -d | dd of=/mnt/volume1 oflag=nocache bs=512 count=1] Namespace:e2e-multivolume-5099 PodName:pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: Checking if read from the volume in pod2 works properly
Oct 20 08:07:48.770: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum] Namespace:e2e-multivolume-5099 PodName:pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:07:48.989: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum | grep -Fq 84efe649f276ff12b2fb71e7afcc70351608e5de38f5c6f7b8bd073909d1840c] Namespace:e2e-multivolume-5099 PodName:pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066 ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:07:49.202: INFO: Deleting pod "pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066" in namespace "e2e-multivolume-5099"
Oct 20 08:07:49.229: INFO: Wait up to 5m0s for pod "pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066" to be fully deleted
STEP: Rechecking if the volume in pod1 exists as expected volume mode (Block)
Oct 20 08:08:03.274: INFO: ExecWithOptions {Command:[/bin/sh -c test -b /mnt/volume1] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:08:03.471: INFO: ExecWithOptions {Command:[/bin/sh -c test -d /mnt/volume1] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: From pod1, rechecking if reading the data that last pod write works properly
Oct 20 08:08:03.698: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:08:03.907: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum | grep -Fq 84efe649f276ff12b2fb71e7afcc70351608e5de38f5c6f7b8bd073909d1840c] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: Rechecking if write to the volume in pod1 works properly
Oct 20 08:08:04.112: INFO: ExecWithOptions {Command:[/bin/sh -c echo 3VzakZOp+6oCFcfuwQCCxL88Q4QZ+7zHowqtKuXLsEjmh2LFqb8pg+yuJb03ZlFQ+f/lc0BJ0ikpuPnDt/ziV7oZOEFX9vLeme6ujVjW9Zz3ZrWdVV1HXqWOOeNKB4BcNkQiZs3U/L4nmfVHrSQSK5J3k3WmGauJnq+YQ0OJ642BGKbo98DuN+nDMYNXdw/WR3cpxaCqvAQ7GmSv14YYc86ZIWjn+yhi6/jFZGgMpHg4asmU9Px/k7/vTIE3/AeLt9288RhYecpq9YxaeRLkJUbh+tuigpc1MdNEo21TWXQC7/7peSNfWBPpVpkiu8tmcl9IG5QfIoeWl5JpV9viCRilGvY9lKDjrFDW0cR5ZmWbbdBrKtELhCWrOZiVOGwrssLKjjjx9G4QGCz3liFPdoCxk2YA7eqh7f5nlzjb7R9ARTXfZpgMpbUemCTJLY1L5LthHcPf2KeUQ9MUOEiUZ7Ssko9KWHiBL4NLoWWp7OOIfvE+UOpgQ0ZiKOCqthhtVZW6gFP4Xojf9A+gxX2JZyF5sthn5Kz/0t7VVrvO+FFgWS9gMtTP+k6ROrCsS3Pb3SlZD3R1dD75lF8aY1oMyNRsbudvvIL45DZJ8EzF7oQ2TjDxG5zPaqPnZKShXVTYwHvVPW/dLb5hdwhvEEl8MT5SSZkj4ZQN57cHLrphbAU= | base64 -d | sha256sum] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:08:04.309: INFO: ExecWithOptions {Command:[/bin/sh -c echo 3VzakZOp+6oCFcfuwQCCxL88Q4QZ+7zHowqtKuXLsEjmh2LFqb8pg+yuJb03ZlFQ+f/lc0BJ0ikpuPnDt/ziV7oZOEFX9vLeme6ujVjW9Zz3ZrWdVV1HXqWOOeNKB4BcNkQiZs3U/L4nmfVHrSQSK5J3k3WmGauJnq+YQ0OJ642BGKbo98DuN+nDMYNXdw/WR3cpxaCqvAQ7GmSv14YYc86ZIWjn+yhi6/jFZGgMpHg4asmU9Px/k7/vTIE3/AeLt9288RhYecpq9YxaeRLkJUbh+tuigpc1MdNEo21TWXQC7/7peSNfWBPpVpkiu8tmcl9IG5QfIoeWl5JpV9viCRilGvY9lKDjrFDW0cR5ZmWbbdBrKtELhCWrOZiVOGwrssLKjjjx9G4QGCz3liFPdoCxk2YA7eqh7f5nlzjb7R9ARTXfZpgMpbUemCTJLY1L5LthHcPf2KeUQ9MUOEiUZ7Ssko9KWHiBL4NLoWWp7OOIfvE+UOpgQ0ZiKOCqthhtVZW6gFP4Xojf9A+gxX2JZyF5sthn5Kz/0t7VVrvO+FFgWS9gMtTP+k6ROrCsS3Pb3SlZD3R1dD75lF8aY1oMyNRsbudvvIL45DZJ8EzF7oQ2TjDxG5zPaqPnZKShXVTYwHvVPW/dLb5hdwhvEEl8MT5SSZkj4ZQN57cHLrphbAU= | base64 -d | dd of=/mnt/volume1 oflag=nocache bs=512 count=1] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
STEP: Rechecking if read from the volume in pod1 works properly
Oct 20 08:08:04.529: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:08:04.732: INFO: ExecWithOptions {Command:[/bin/sh -c dd if=/mnt/volume1 iflag=direct bs=512 count=1 | sha256sum | grep -Fq 3cc68a630633abb8dc92d09fd06b67c50e78973f5010de43159f75342262e315] Namespace:e2e-multivolume-5099 PodName:pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f ContainerName:write-pod Stdin:<nil> CaptureStdout:true CaptureStderr:true PreserveWhitespace:false}
Oct 20 08:08:04.958: INFO: Deleting pod "pod-3a1ce6cb-a927-460e-bf51-8f52a1e32066" in namespace "e2e-multivolume-5099"
Oct 20 08:08:04.982: INFO: Deleting pod "pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f" in namespace "e2e-multivolume-5099"
Oct 20 08:08:05.007: INFO: Wait up to 5m0s for pod "pod-c2ab5158-a864-4cc4-8f29-4a5f756be89f" to be fully deleted
STEP: Deleting pvc
Oct 20 08:08:11.053: INFO: Deleting PersistentVolumeClaim "openshift-storage.rbd.csi.ceph.comxsp5q"
Oct 20 08:08:11.079: INFO: Waiting up to 5m0s for PersistentVolume pvc-6ee7e263-b493-49ea-bf73-cb37de2a1ae9 to get deleted
Oct 20 08:08:11.129: INFO: PersistentVolume pvc-6ee7e263-b493-49ea-bf73-cb37de2a1ae9 found and phase=Released (49.541712ms)
Oct 20 08:08:16.151: INFO: PersistentVolume pvc-6ee7e263-b493-49ea-bf73-cb37de2a1ae9 was removed
STEP: Deleting sc
[AfterEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  k8s.io/kubernetes.0/test/e2e/framework/framework.go:175
Oct 20 08:08:16.180: INFO: Waiting up to 7m0s for all (but 100) nodes to be ready
STEP: Destroying namespace "e2e-multivolume-5099" for this suite.
Oct 20 08:08:16.274: INFO: Running AfterSuite actions on all nodes
Oct 20 08:08:16.275: INFO: Running AfterSuite actions on node 1

passed: (59.9s) 2020-10-20T08:08:16 "External Storage [Driver: openshift-storage.rbd.csi.ceph.com] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] should concurrently access the single volume from pods on different node"

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Moderate: OpenShift Container Platform 4.7.0 security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2020:5633