Docker in Docker enabled, initializing...
================================================================================
Starting Docker: docker.
Waiting for docker to be ready, sleeping for 1 seconds.
[Barnacle] 2019/12/12 00:12:24 Cleaning up Docker data root...
[Barnacle] 2019/12/12 00:12:24 Removing all containers.
[Barnacle] 2019/12/12 00:12:24 Removing recently created images.
[Barnacle] 2019/12/12 00:12:24 Pruning dangling images.
[Barnacle] 2019/12/12 00:12:24 Pruning volumes.
[Barnacle] 2019/12/12 00:12:24 Volume Prune results: {"VolumesDeleted":[],"SpaceReclaimed":0}
[Barnacle] 2019/12/12 00:12:24 Done cleaning up Docker data root.
Remaining docker images and volumes are:
REPOSITORY          TAG                 IMAGE ID            CREATED             SIZE
DRIVER              VOLUME NAME
Cleaning up binfmt_misc ...
================================================================================
Done setting up docker in docker.
Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
+ kubetest --test --up --down --deployment=acsengine --build=quick --provider=azure --acsengine-agentpoolcount=2 --acsengine-admin-username=azureuser --acsengine-creds=/etc/azure-cred/credentials --acsengine-orchestratorRelease=1.17 --acsengine-mastervmsize=Standard_DS2_v2 --acsengine-agentvmsize=Standard_D4s_v3 --aksengine-deploy-custom-k8s --acsengine-location=westus2 --acsengine-public-key=/etc/azure-ssh/azure-ssh-pub --acsengine-template-url=https://raw.githubusercontent.com/kubernetes-sigs/azuredisk-csi-driver/master/test/e2e/manifest/in-tree-vmss.json --acsengine-download-url=https://chuwon.blob.core.windows.net/aks-engine/aks-engine-master-linux-amd64.tar.gz --ginkgo-parallel=5 '--test_args=--ginkgo.flakeAttempts=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]|default\sfs.*should\sverify\scontainer\scannot\swrite\sto\ssubpath\sreadonly\svolumes' --timeout=420m
2019/12/12 00:12:30 main.go:332: Limiting testing to 7h0m0s
2019/12/12 00:12:30 azure.go:274: Reading credentials file /etc/azure-cred/credentials
2019/12/12 00:12:30 azure.go:823: CWD /home/prow/go/src/github.com/Azure/kubernetes
2019/12/12 00:12:30 azure.go:842: Attempting Docker login with azure cred.
2019/12/12 00:12:31 azure.go:851: Docker login success.
2019/12/12 00:12:31 process.go:153: Running: make -C /home/prow/go/src/k8s.io/kubernetes quick-release
make: Entering directory '/home/prow/go/src/k8s.io/kubernetes'
+++ [1212 00:12:31] Verifying Prerequisites....
+++ [1212 00:12:31] Building Docker image kube-build:build-5a5be15e25-5-v1.13.4-1
+++ [1212 00:15:15] Creating data container kube-build-data-5a5be15e25-5-v1.13.4-1
+++ [1212 00:15:47] Syncing sources to container
+++ [1212 00:15:55] Running build command...
+++ [1212 00:16:03] Building go targets for linux/amd64:
    ./vendor/k8s.io/code-generator/cmd/deepcopy-gen
+++ [1212 00:16:09] Building go targets for linux/amd64:
    ./vendor/k8s.io/code-generator/cmd/defaulter-gen
+++ [1212 00:16:15] Building go targets for linux/amd64:
    ./vendor/k8s.io/code-generator/cmd/conversion-gen
+++ [1212 00:16:24] Building go targets for linux/amd64:
    ./vendor/k8s.io/kube-openapi/cmd/openapi-gen
+++ [1212 00:16:35] Building go targets for linux/amd64:
    ./vendor/github.com/go-bindata/go-bindata/go-bindata
+++ [1212 00:16:36] Building go targets for linux/amd64:
    cmd/kube-proxy
    cmd/kube-apiserver
    cmd/kube-controller-manager
    cmd/kubelet
    cmd/kubeadm
    cmd/kube-scheduler
    vendor/k8s.io/apiextensions-apiserver
    cluster/gce/gci/mounter
+++ [1212 00:19:32] Building go targets for linux/amd64:
    cmd/kube-proxy
    cmd/kubeadm
    cmd/kubelet
+++ [1212 00:19:40] Building go targets for linux/amd64:
    cmd/kubectl
+++ [1212 00:20:04] Building go targets for linux/amd64:
    cmd/gendocs
    cmd/genkubedocs
    cmd/genman
    cmd/genyaml
    cmd/genswaggertypedocs
    cmd/linkcheck
    vendor/github.com/onsi/ginkgo/ginkgo
    test/e2e/e2e.test
    cluster/images/conformance/go-runner
+++ [1212 00:22:09] Building go targets for linux/amd64:
    cmd/kubemark
    vendor/github.com/onsi/ginkgo/ginkgo
    test/e2e_node/e2e_node.test
+++ [1212 00:23:22] Syncing out of container
+++ [1212 00:23:55] Building tarball: manifests
+++ [1212 00:23:55] Building tarball: src
+++ [1212 00:23:55] Starting tarball: client linux-amd64
+++ [1212 00:23:55] Waiting on tarballs
+++ [1212 00:24:01] Building tarball: node linux-amd64
+++ [1212 00:24:01] Building images: linux-amd64
+++ [1212 00:24:01] Starting docker build for image: kube-apiserver-amd64
+++ [1212 00:24:01] Starting docker build for image: kube-controller-manager-amd64
+++ [1212 00:24:01] Starting docker build for image: kube-scheduler-amd64
+++ [1212 00:24:01] Starting docker build for image: kube-proxy-amd64
+++ [1212 00:24:01] Building conformance image for arch: amd64
+++ [1212 00:24:01] Building hyperkube image for arch: amd64
+++ [1212 00:24:37] Tagging docker image k8s.gcr.io/kube-scheduler-amd64:v1.18.0-alpha.0.1670_0d58709016f335 as k8sprowinternal.azurecr.io/kube-scheduler-amd64:azure-e2e-1204916450456768512
+++ [1212 00:24:37] Tagging docker image k8s.gcr.io/kube-controller-manager-amd64:v1.18.0-alpha.0.1670_0d58709016f335 as k8sprowinternal.azurecr.io/kube-controller-manager-amd64:azure-e2e-1204916450456768512
+++ [1212 00:24:37] Tagging docker image k8s.gcr.io/kube-apiserver-amd64:v1.18.0-alpha.0.1670_0d58709016f335 as k8sprowinternal.azurecr.io/kube-apiserver-amd64:azure-e2e-1204916450456768512
+++ [1212 00:24:47] Deleting docker image k8s.gcr.io/kube-scheduler-amd64:v1.18.0-alpha.0.1670_0d58709016f335
+++ [1212 00:24:50] Deleting docker image k8s.gcr.io/kube-controller-manager-amd64:v1.18.0-alpha.0.1670_0d58709016f335
+++ [1212 00:24:50] Deleting docker image k8s.gcr.io/kube-apiserver-amd64:v1.18.0-alpha.0.1670_0d58709016f335
+++ [1212 00:24:53] Tagging docker image k8s.gcr.io/kube-proxy-amd64:v1.18.0-alpha.0.1670_0d58709016f335 as k8sprowinternal.azurecr.io/kube-proxy-amd64:azure-e2e-1204916450456768512
+++ [1212 00:25:01] Deleting docker image k8s.gcr.io/kube-proxy-amd64:v1.18.0-alpha.0.1670_0d58709016f335
+++ [1212 00:25:29] Deleting hyperkube image k8s.gcr.io/hyperkube-amd64:v1.18.0-alpha.0.1670_0d58709016f335
+++ [1212 00:25:55] Deleting conformance image k8s.gcr.io/conformance-amd64:v1.18.0-alpha.0.1670_0d58709016f335
+++ [1212 00:25:56] Docker builds done
+++ [1212 00:25:56] Building tarball: server linux-amd64
+++ [1212 00:27:03] Building tarball: final
+++ [1212 00:27:03] Waiting on test tarballs
+++ [1212 00:27:03] Starting tarball: test linux-amd64
+++ [1212 00:27:49] Building tarball: test portable
make: Leaving directory '/home/prow/go/src/k8s.io/kubernetes'
2019/12/12 00:27:49 process.go:155: Step 'make -C /home/prow/go/src/k8s.io/kubernetes quick-release' finished in 15m18.567003244s
2019/12/12 00:27:49 azure.go:856: Pushing docker image k8sprowinternal.azurecr.io/kube-apiserver-amd64:azure-e2e-1204916450456768512
2019/12/12 00:28:00 azure.go:856: Pushing docker image k8sprowinternal.azurecr.io/kube-controller-manager-amd64:azure-e2e-1204916450456768512
2019/12/12 00:28:08 azure.go:856: Pushing docker image k8sprowinternal.azurecr.io/kube-proxy-amd64:azure-e2e-1204916450456768512
2019/12/12 00:28:12 azure.go:856: Pushing docker image k8sprowinternal.azurecr.io/kube-scheduler-amd64:azure-e2e-1204916450456768512
2019/12/12 00:28:17 azure.go:1125: Renaming /home/prow/go/src/k8s.io/kubernetes/_output/release-tars/kubernetes-node-linux-amd64.tar.gz to /home/prow/go/src/k8s.io/kubernetes/_output/release-tars/kubernetes-node-linux-amd64-1204916450456768512.tar.gz
2019/12/12 00:28:19 azure.go:951: Uploaded /home/prow/go/src/k8s.io/kubernetes/_output/release-tars/kubernetes-node-linux-amd64-1204916450456768512.tar.gz to https://upstreamprowstorageacct.blob.core.windows.net/mystoragecontainer/kubernetes-node-linux-amd64-1204916450456768512.tar.gz
2019/12/12 00:28:19 util.go:265: Flushing memory.
2019/12/12 00:28:21 azure.go:1137: Deleting resource group: kubetest-163a5b0d-1c74-11ea-bbe3-02428835837c.
2019/12/12 00:28:22 azure.go:964: downloading /root/aks568628239/kubernetes.json from https://raw.githubusercontent.com/kubernetes-sigs/azuredisk-csi-driver/master/test/e2e/manifest/in-tree-vmss.json.
2019/12/12 00:28:22 util.go:42: curl https://raw.githubusercontent.com/kubernetes-sigs/azuredisk-csi-driver/master/test/e2e/manifest/in-tree-vmss.json
2019/12/12 00:28:22 azure.go:664: downloading /root/aks-engine.tar.gz from https://chuwon.blob.core.windows.net/aks-engine/aks-engine-master-linux-amd64.tar.gz.
2019/12/12 00:28:22 util.go:42: curl https://chuwon.blob.core.windows.net/aks-engine/aks-engine-master-linux-amd64.tar.gz
2019/12/12 00:28:22 azure.go:691: Extracting tar file /root/aks-engine.tar.gz into directory /home/prow/go/src/github.com/Azure/kubernetes .
2019/12/12 00:28:22 process.go:153: Running: tar -xzf /root/aks-engine.tar.gz --strip 1
2019/12/12 00:28:22 process.go:155: Step 'tar -xzf /root/aks-engine.tar.gz --strip 1' finished in 128.156853ms
2019/12/12 00:28:22 process.go:153: Running: /home/prow/go/src/github.com/Azure/kubernetes/aks-engine generate /root/aks568628239/kubernetes.json --output-directory /root/aks568628239
INFO[0000] Generating assets into /root/aks568628239... 
2019/12/12 00:28:32 process.go:155: Step '/home/prow/go/src/github.com/Azure/kubernetes/aks-engine generate /root/aks568628239/kubernetes.json --output-directory /root/aks568628239' finished in 9.652681071s
2019/12/12 00:28:32 azure.go:762: Setting kubeconfig env variable: kubeconfig path: /root/aks568628239/kubeconfig/kubeconfig.westus2.json.
2019/12/12 00:28:32 azure.go:764: Creating resource group: kubetest-163a5b0d-1c74-11ea-bbe3-02428835837c.
2019/12/12 00:28:32 azure.go:766: Creating Azure resource group: kubetest-163a5b0d-1c74-11ea-bbe3-02428835837c for cluster deployment.
2019/12/12 00:28:32 azure.go:771: Validating deployment ARM templates.
2019/12/12 00:28:33 azure.go:777: Deploying cluster kubetest-163a5b0d-1c74-11ea-bbe3-02428835837c in resource group kubetest-163a5b0d-1c74-11ea-bbe3-02428835837c.
2019/12/12 00:36:35 process.go:153: Running: kubectl --match-server-version=false version
2019/12/12 00:36:35 process.go:155: Step 'kubectl --match-server-version=false version' finished in 358.115143ms
2019/12/12 00:36:35 azure.go:1201: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos.
2019/12/12 00:36:35 azure.go:1201: KUBE_TEST_REPO_LIST_DOWNLOAD_LOCATION not set. Using default test image repos.
2019/12/12 00:36:35 process.go:153: Running: kubectl get nodes --no-headers
2019/12/12 00:36:36 process.go:155: Step 'kubectl get nodes --no-headers' finished in 931.478755ms
2019/12/12 00:36:36 e2e.go:474: Cluster nodes:
k8s-agentpool1-27089080-vmss000000   Ready   agent    39s   v1.18.0-alpha.0.1670+0d58709016f335
k8s-agentpool1-27089080-vmss000001   Ready   agent    39s   v1.18.0-alpha.0.1670+0d58709016f335
k8s-master-27089080-0                Ready   master   39s   v1.18.0-alpha.0.1670+0d58709016f335
2019/12/12 00:36:36 process.go:153: Running: kubectl --match-server-version=false version
2019/12/12 00:36:36 process.go:155: Step 'kubectl --match-server-version=false version' finished in 137.358829ms
2019/12/12 00:36:36 process.go:153: Running: ./hack/ginkgo-e2e.sh --ginkgo.flakeAttempts=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]|default\sfs.*should\sverify\scontainer\scannot\swrite\sto\ssubpath\sreadonly\svolumes
Conformance test: not doing test setup.
It looks as if you don't have a compiled kubectl binary

If you are running from a clone of the git repo, please run
'./build/run.sh make cross'. Note that this requires having
Docker installed.

If you are running from a binary release tarball, something is wrong. 
Look at http://kubernetes.io/ for information on how to contact the 
development team for help.
!!! [1212 00:36:36] Call tree:
!!! [1212 00:36:36]  1: ./hack/ginkgo-e2e.sh:66 detect-master-from-kubeconfig(...)
2019/12/12 00:36:36 process.go:155: Step './hack/ginkgo-e2e.sh --ginkgo.flakeAttempts=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]|default\sfs.*should\sverify\scontainer\scannot\swrite\sto\ssubpath\sreadonly\svolumes' finished in 89.799338ms
2019/12/12 00:36:36 azure.go:1137: Deleting resource group: kubetest-163a5b0d-1c74-11ea-bbe3-02428835837c.
2019/12/12 00:44:22 main.go:319: Something went wrong: encountered 1 errors: [error during ./hack/ginkgo-e2e.sh --ginkgo.flakeAttempts=2 --ginkgo.focus=azure-disk --ginkgo.skip=\[Serial\]|\[Disruptive\]|\[Flaky\]|\[Feature:.+\]|default\sfs.*should\sverify\scontainer\scannot\swrite\sto\ssubpath\sreadonly\svolumes: exit status 1]
+ EXIT_VALUE=1
+ set +o xtrace
Cleaning up after docker in docker.
================================================================================
[Barnacle] 2019/12/12 00:44:22 Cleaning up Docker data root...
[Barnacle] 2019/12/12 00:44:22 Removing all containers.
[Barnacle] 2019/12/12 00:44:22 Stopping container: [/kube-build-data-5a5be15e25-5-v1.13.4-1] kube-build:build-5a5be15e25-5-v1.13.4-1 with ID: af5cc80efa3cbe0bc94330632aaa7a69515bda2a6f6e42d89ad005e36281d7b2
[Barnacle] 2019/12/12 00:44:22 Removing container: [/kube-build-data-5a5be15e25-5-v1.13.4-1] kube-build:build-5a5be15e25-5-v1.13.4-1 with ID: af5cc80efa3cbe0bc94330632aaa7a69515bda2a6f6e42d89ad005e36281d7b2
[Barnacle] 2019/12/12 00:44:23 Removing recently created images.
[Barnacle] 2019/12/12 00:44:23 Deleting image: [k8sprowinternal.azurecr.io/kube-proxy-amd64:azure-e2e-1204916450456768512] with ID: sha256:dab86e04bd633d069a1728f42562fae92899bd44eda0b29fc1c1129a6808fe66 and size 130192267
[Barnacle] 2019/12/12 00:44:32 Deleting image: [k8sprowinternal.azurecr.io/kube-apiserver-amd64:azure-e2e-1204916450456768512] with ID: sha256:071425413853e27e719e7168d3bbe790d44b69bd305ae61aeebb4d0182eed5bb and size 212483476
[Barnacle] 2019/12/12 00:44:32 Deleting image: [k8sprowinternal.azurecr.io/kube-controller-manager-amd64:azure-e2e-1204916450456768512] with ID: sha256:1b3e2921f2630d1eb251ca0b95e94aae63f7c6a962a983f85a42082b302e8af8 and size 200848265
[Barnacle] 2019/12/12 00:44:32 Deleting image: [k8sprowinternal.azurecr.io/kube-scheduler-amd64:azure-e2e-1204916450456768512] with ID: sha256:5a1a05be0a8ed967b928e4fa4e6d6d0fd1bfa8c26178f653724b27438b7fbfcd and size 110518646
[Barnacle] 2019/12/12 00:44:32 Deleting image: [kube-build:build-5a5be15e25-5-v1.13.4-1] with ID: sha256:209817ebfbd7b8964e7ae1dc6a47ba1282fdee22f4f4091a7c8461ded8c43e9c and size 2581536742
[Barnacle] 2019/12/12 00:44:32 Pruning dangling images.
[Barnacle] 2019/12/12 00:44:32 Pruning volumes.
[Barnacle] 2019/12/12 00:44:32 Volume Prune results: {"VolumesDeleted":[],"SpaceReclaimed":0}
[Barnacle] 2019/12/12 00:44:32 Done cleaning up Docker data root.
Remaining docker images and volumes are:
REPOSITORY                               TAG                 IMAGE ID            CREATED             SIZE
k8s.gcr.io/debian-iptables-amd64         v12.0.1             2ab74e969307        4 weeks ago         78.2MB
k8s.gcr.io/kube-cross                    v1.13.4-1           cb825830a0c3        5 weeks ago         1.89GB
k8s.gcr.io/debian-base-amd64             v2.0.0              9bd615472442        5 weeks ago         52.3MB
k8s.gcr.io/debian-hyperkube-base-amd64   0.12.1              a46476511725        10 months ago       393MB
DRIVER              VOLUME NAME
Cleaning up binfmt_misc ...
================================================================================
Done cleaning up after docker in docker.