Test got terminated randomly after upgrading to gcr.io/k8s-testimages/kubekins-e2e:v20191017-ac4b4b5-master

[Random-Liu]

Right after the upgrade 71aae2c#diff-bc1a19dd8cab7a55902e9a81d5f4d935

The containerd windows test starts being randomly terminated in the middle of the test.
We start seeing this right after that image update.

[Random-Liu]

An example test failure https://prow.k8s.io/view/gcs/kubernetes-jenkins/logs/ci-cri-containerd-cri-validation-windows/1184908137358954497

And from the dashboard https://k8s-testgrid.appspot.com/sig-node-containerd#cri-validation-windows, we can see that the first failure started since 10-17 12:04, and the change was merged at 10-17 11:08.

[BenTheElder]

do you have a specific example?
edit: there's a lot of noise in https://prow.k8s.io/view/gcs/kubernetes-jenkins/logs/ci-cri-containerd-cri-validation-windows/1184908137358954497, which part specifically?

[Random-Liu]

In some of the test failure, we can find this:
cat: write error: Resource temporarily unavailable

For example: https://storage.googleapis.com/kubernetes-jenkins/logs/ci-cri-containerd-cri-validation-windows/1185015668978749444/build-log.txt

[Random-Liu]

This seems to be a bash issue, there are some previous bug reports, haven't looked into them yet:

• cat: write error: Resource temporarily unavailable nodejs/node#19838
• EPIPE with the repl and cat? nodejs/node-v0.x-archive#3027

If it is a bash issue, it could be caused by the debian update from stretch to buster.

[Random-Liu]

Based on nodejs/node#14752, it seems that something set the stdout to O_NONBLOCK mode, and cat a large file will hit cat: write error: Resource temporarily unavailable in that mode.

The windows test runs a lot of gcloud ssh and gcloud scp command, and gcloud is also updated in that window:

$ docker run --entrypoint=/bin/bash gcr.io/k8s-testimages/kubekins-e2e:v20191017-ac4b4b5-master gcloud version
Google Cloud SDK 267.0.0
alpha 2019.05.17
beta 2019.05.17
bq 2.0.49
core 2019.10.15
gsutil 4.44
kubectl 2019.09.22

$ docker run --entrypoint=/bin/bash gcr.io/k8s-testimages/kubekins-e2e:v20191012-482f444-master gcloud version
Google Cloud SDK 250.0.0
alpha 2019.05.17
beta 2019.05.17
bq 2.0.43
core 2019.06.07
gsutil 4.38
kubectl 2019.06.07

It seems very likely to be a bug in the new gcloud version that it sets the stdout to O_NONBLOCK mode.

I'll try applying the fix uwcirg/truenth-portal#2689 to the test for now to set the stdout back before the large cat.

[Random-Liu]

It does turn out that O_NONBLOCK is set by something containerd/cri#1324:

+ python -c 'import os,sys,fcntl; flags = fcntl.fcntl(sys.stdout, fcntl.F_GETFL); print(flags&os.O_NONBLOCK);'
2048
+ python -c 'import os,sys,fcntl; flags = fcntl.fcntl(sys.stdout, fcntl.F_GETFL); fcntl.

I highly suspect that it is gcloud.

Anyway, I think it is more a gcloud issue than a test-infra issue. I'll close this one for now. And for people who hits similar issue in the future, they can reference this issue to find a workaround.