Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

flake: crio: Back-off pulling image "openshift/origin-deployer:4762d6a" #18365

Closed
tnozicka opened this issue Jan 31, 2018 · 5 comments
Closed

flake: crio: Back-off pulling image "openshift/origin-deployer:4762d6a" #18365

tnozicka opened this issue Jan 31, 2018 · 5 comments
Assignees
@runcom @stevekuznetsov
Labels
area/tests kind/test-flake Categorizes issue or PR as related to test flakes. priority/P1

Comments

@tnozicka
Copy link
Contributor

crio job is failing because it can't pull deployer image openshift/origin-deployer:4762d6a

This is #1 flake (49 times) in https://snowstorm-origin-ci.svc.ci.openshift.org/

@mfojtik @stevekuznetsov @runcom

deployer image should be pre-pulled likely or at least pulled faster than 5 minutes.

  containerStatuses:
  - image: openshift/origin-deployer:4762d6a
    imageID: ""
    lastState: {}
    name: deployment
    ready: false
    restartCount: 0
    state:
      waiting:
        message: Back-off pulling image "openshift/origin-deployer:4762d6a"
        reason: ImagePullBackOff

https://ci.openshift.redhat.com/jenkins/job/test_branch_origin_extended_conformance_crio/503/consoleFull

[Feature:DeploymentConfig] deploymentconfigs won't deploy RC with unresolved images [Conformance] 
  when patched with empty image [Suite:openshift/conformance/parallel]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:1405

[BeforeEach] [Top Level]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/util/test.go:53
[BeforeEach] [Feature:DeploymentConfig] deploymentconfigs
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:134
STEP: Creating a kubernetes client
Jan 27 14:14:23.646: INFO: >>> kubeConfig: /etc/origin/master/admin.kubeconfig
STEP: Building a namespace api object
Jan 27 14:14:23.670: INFO: configPath is now "/tmp/extended-test-cli-deployment-j4d8f-xwrkj-user.kubeconfig"
Jan 27 14:14:23.670: INFO: The user is now "extended-test-cli-deployment-j4d8f-xwrkj-user"
Jan 27 14:14:23.670: INFO: Creating project "extended-test-cli-deployment-j4d8f-xwrkj"
Jan 27 14:14:23.735: INFO: Waiting on permissions in project "extended-test-cli-deployment-j4d8f-xwrkj" ...
STEP: Waiting for a default service account to be provisioned in namespace
[JustBeforeEach] [Feature:DeploymentConfig] deploymentconfigs
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:43
[It] when patched with empty image [Suite:openshift/conformance/parallel]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:1405
STEP: creating DC
STEP: tagging the busybox:latest as test:v1 image to create ImageStream
Jan 27 14:14:23.775: INFO: Running 'oc tag --config=/tmp/extended-test-cli-deployment-j4d8f-xwrkj-user.kubeconfig --namespace=extended-test-cli-deployment-j4d8f-xwrkj docker.io/busybox:latest test:v1'
Jan 27 14:14:24.055: INFO: Tag test:v1 set to docker.io/busybox:latest.
STEP: waiting for deployment #1 to complete
[AfterEach] won't deploy RC with unresolved images [Conformance]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:1401
Jan 27 14:19:24.061: INFO: Running 'oc get --config=/tmp/extended-test-cli-deployment-j4d8f-xwrkj-user.kubeconfig --namespace=extended-test-cli-deployment-j4d8f-xwrkj dc/example -o yaml'
Jan 27 14:19:24.314: INFO: 
apiVersion: v1
kind: DeploymentConfig
metadata:
  creationTimestamp: 2018-01-27T14:14:23Z
  generation: 2
  labels:
    app: example
  name: example
  namespace: extended-test-cli-deployment-j4d8f-xwrkj
  resourceVersion: "42060"
  selfLink: /oapi/v1/namespaces/extended-test-cli-deployment-j4d8f-xwrkj/deploymentconfigs/example
  uid: 600c3ed1-036c-11e8-ba4b-0e7ab02740dc
spec:
  replicas: 1
  revisionHistoryLimit: 10
  selector:
    app: example
  strategy:
    activeDeadlineSeconds: 21600
    resources: {}
    rollingParams:
      intervalSeconds: 1
      maxSurge: 25%
      maxUnavailable: 25%
      timeoutSeconds: 600
      updatePeriodSeconds: 1
    type: Rolling
  template:
    metadata:
      creationTimestamp: null
      labels:
        app: example
    spec:
      containers:
      - command:
        - /bin/sleep
        - "100"
        image: docker.io/busybox@sha256:4cee1979ba0bf7db9fc5d28fb7b798ca69ae95a47c5fecf46327720df4ff352d
        imagePullPolicy: Always
        name: test
        resources: {}
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
      dnsPolicy: ClusterFirst
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext: {}
      terminationGracePeriodSeconds: 30
  test: false
  triggers:
  - imageChangeParams:
      automatic: true
      containerNames:
      - test
      from:
        kind: ImageStreamTag
        name: test:v1
        namespace: extended-test-cli-deployment-j4d8f-xwrkj
      lastTriggeredImage: docker.io/busybox@sha256:4cee1979ba0bf7db9fc5d28fb7b798ca69ae95a47c5fecf46327720df4ff352d
    type: ImageChange
status:
  availableReplicas: 0
  conditions:
  - lastTransitionTime: 2018-01-27T14:14:23Z
    lastUpdateTime: 2018-01-27T14:14:23Z
    message: Deployment config does not have minimum availability.
    status: "False"
    type: Available
  - lastTransitionTime: 2018-01-27T14:14:24Z
    lastUpdateTime: 2018-01-27T14:14:24Z
    message: replication controller "example-1" is waiting for pod "example-1-deploy"
      to run
    status: Unknown
    type: Progressing
  details:
    causes:
    - type: ConfigChange
    message: config change
  latestVersion: 1
  observedGeneration: 2
  replicas: 0
  unavailableReplicas: 0
  updatedReplicas: 0

Jan 27 14:19:24.328: INFO: Running 'oc get --config=/tmp/extended-test-cli-deployment-j4d8f-xwrkj-user.kubeconfig --namespace=extended-test-cli-deployment-j4d8f-xwrkj rc/example-1 -o yaml'
Jan 27 14:19:24.567: INFO: 
apiVersion: v1
kind: ReplicationController
metadata:
  annotations:
    kubectl.kubernetes.io/desired-replicas: "1"
    openshift.io/deployer-pod.created-at: 2018-01-27 14:14:24 +0000 UTC
    openshift.io/deployer-pod.name: example-1-deploy
    openshift.io/deployment-config.latest-version: "1"
    openshift.io/deployment-config.name: example
    openshift.io/deployment.phase: Pending
    openshift.io/deployment.replicas: "0"
    openshift.io/deployment.status-reason: config change
    openshift.io/encoded-deployment-config: |
      {"kind":"DeploymentConfig","apiVersion":"v1","metadata":{"name":"example","namespace":"extended-test-cli-deployment-j4d8f-xwrkj","selfLink":"/apis/apps.openshift.io/v1/namespaces/extended-test-cli-deployment-j4d8f-xwrkj/deploymentconfigs/example","uid":"600c3ed1-036c-11e8-ba4b-0e7ab02740dc","resourceVersion":"42052","generation":2,"creationTimestamp":"2018-01-27T14:14:23Z","labels":{"app":"example"}},"spec":{"strategy":{"type":"Rolling","rollingParams":{"updatePeriodSeconds":1,"intervalSeconds":1,"timeoutSeconds":600,"maxUnavailable":"25%","maxSurge":"25%"},"resources":{},"activeDeadlineSeconds":21600},"triggers":[{"type":"ImageChange","imageChangeParams":{"automatic":true,"containerNames":["test"],"from":{"kind":"ImageStreamTag","namespace":"extended-test-cli-deployment-j4d8f-xwrkj","name":"test:v1"},"lastTriggeredImage":"docker.io/busybox@sha256:4cee1979ba0bf7db9fc5d28fb7b798ca69ae95a47c5fecf46327720df4ff352d"}}],"replicas":1,"revisionHistoryLimit":10,"test":false,"selector":{"app":"example"},"template":{"metadata":{"creationTimestamp":null,"labels":{"app":"example"}},"spec":{"containers":[{"name":"test","image":"docker.io/busybox@sha256:4cee1979ba0bf7db9fc5d28fb7b798ca69ae95a47c5fecf46327720df4ff352d","command":["/bin/sleep","100"],"resources":{},"terminationMessagePath":"/dev/termination-log","terminationMessagePolicy":"File","imagePullPolicy":"Always"}],"restartPolicy":"Always","terminationGracePeriodSeconds":30,"dnsPolicy":"ClusterFirst","securityContext":{},"schedulerName":"default-scheduler"}}},"status":{"latestVersion":1,"observedGeneration":1,"replicas":0,"updatedReplicas":0,"availableReplicas":0,"unavailableReplicas":0,"details":{"message":"config change","causes":[{"type":"ConfigChange"}]},"conditions":[{"type":"Available","status":"False","lastUpdateTime":"2018-01-27T14:14:23Z","lastTransitionTime":"2018-01-27T14:14:23Z","message":"Deployment config does not have minimum availability."}]}}
  creationTimestamp: 2018-01-27T14:14:24Z
  generation: 1
  labels:
    app: example
    openshift.io/deployment-config.name: example
  name: example-1
  namespace: extended-test-cli-deployment-j4d8f-xwrkj
  ownerReferences:
  - apiVersion: apps.openshift.io/v1
    blockOwnerDeletion: true
    controller: true
    kind: DeploymentConfig
    name: example
    uid: 600c3ed1-036c-11e8-ba4b-0e7ab02740dc
  resourceVersion: "42059"
  selfLink: /api/v1/namespaces/extended-test-cli-deployment-j4d8f-xwrkj/replicationcontrollers/example-1
  uid: 6059717f-036c-11e8-ba4b-0e7ab02740dc
spec:
  replicas: 0
  selector:
    app: example
    deployment: example-1
    deploymentconfig: example
  template:
    metadata:
      annotations:
        openshift.io/deployment-config.latest-version: "1"
        openshift.io/deployment-config.name: example
        openshift.io/deployment.name: example-1
      creationTimestamp: null
      labels:
        app: example
        deployment: example-1
        deploymentconfig: example
    spec:
      containers:
      - command:
        - /bin/sleep
        - "100"
        image: docker.io/busybox@sha256:4cee1979ba0bf7db9fc5d28fb7b798ca69ae95a47c5fecf46327720df4ff352d
        imagePullPolicy: Always
        name: test
        resources: {}
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
      dnsPolicy: ClusterFirst
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext: {}
      terminationGracePeriodSeconds: 30
status:
  observedGeneration: 1
  replicas: 0

Jan 27 14:19:24.567: INFO: Running 'oc get --config=/tmp/extended-test-cli-deployment-j4d8f-xwrkj-user.kubeconfig --namespace=extended-test-cli-deployment-j4d8f-xwrkj pod/example-1-deploy -o yaml'
Jan 27 14:19:24.809: INFO: 
apiVersion: v1
kind: Pod
metadata:
  annotations:
    openshift.io/deployment-config.name: example
    openshift.io/deployment.name: example-1
    openshift.io/scc: restricted
  creationTimestamp: 2018-01-27T14:14:24Z
  labels:
    openshift.io/deployer-pod-for.name: example-1
  name: example-1-deploy
  namespace: extended-test-cli-deployment-j4d8f-xwrkj
  ownerReferences:
  - apiVersion: v1
    kind: ReplicationController
    name: example-1
    uid: 6059717f-036c-11e8-ba4b-0e7ab02740dc
  resourceVersion: "42466"
  selfLink: /api/v1/namespaces/extended-test-cli-deployment-j4d8f-xwrkj/pods/example-1-deploy
  uid: 605ce612-036c-11e8-ba4b-0e7ab02740dc
spec:
  activeDeadlineSeconds: 21600
  containers:
  - env:
    - name: KUBERNETES_MASTER
      value: https://ip-172-18-12-166.ec2.internal:8443
    - name: OPENSHIFT_MASTER
      value: https://ip-172-18-12-166.ec2.internal:8443
    - name: BEARER_TOKEN_FILE
      value: /var/run/secrets/kubernetes.io/serviceaccount/token
    - name: OPENSHIFT_CA_DATA
      value: |
        -----BEGIN CERTIFICATE-----
        MIIC6jCCAdKgAwIBAgIBATANBgkqhkiG9w0BAQsFADAmMSQwIgYDVQQDDBtvcGVu
        c2hpZnQtc2lnbmVyQDE1MTcwNTI0NjMwHhcNMTgwMTI3MTEyNzQzWhcNMjMwMTI2
        MTEyNzQ0WjAmMSQwIgYDVQQDDBtvcGVuc2hpZnQtc2lnbmVyQDE1MTcwNTI0NjMw
        ggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQC1sNtqcZ2QeHVzzQsM/xVl
        yZ8h8XGzw8P3o+0m1LpfyzyvuJmc5xzvcBL1b5DNMk5BnOVrH8gPFSCUpTBM8sn7
        ODAxq++GXdPM4tfCM9feSR7XxEoGGu/pN4jUY4UGWOSFgdjOjub1GwTnfMziXS7S
        eLwOTN/vUFRbquTUnTMcbpOJIBn/+dsP0mKu5ySMKYPJp2IZO6eHfBclqSWzLgs8
        k1s7y0dTK7CvxZpi15/3g2b6E38AAWYDltu0ljuFJqcYMuDyIHP16peX3KUjCkWb
        f5LWCWQY+Ll8FToD8V+2gh7P5jJwNn3lyxVDpJ8uVL9zL6/DfzJ1ulTZDPKnzpR/
        AgMBAAGjIzAhMA4GA1UdDwEB/wQEAwICpDAPBgNVHRMBAf8EBTADAQH/MA0GCSqG
        SIb3DQEBCwUAA4IBAQAqUQwfUJhOAjY4LRf6PkAQLyx3/SCdC38HS8x/Yk07qiZX
        9vwqkkdgEvGtDxRAOTh8Vp7x3PxkcbCfv1OY89AJe6qOINvQ07QEzH6gH6hhr0y4
        Qd6lMN7QMKlsk2nxXYwaDoPJKX6I+PTYeYoYlTLiLUwaGrxL3b2u7eXHk6TPqMyE
        Xv/idy6PCaFo1pShlcosHEcA2fZpZ6te2nlJX0kCTs3bIefWK0HU8rXfjstQjDUE
        OZAnS58yoZ/CrG+TLdKrPKuhkA3UQAleHgn0Ngyia1y092DZpV4bbypQz5Wcn37y
        haRjXnmKPolftFv8WnFIsDxRITDgaoqHRfIRQoe7
        -----END CERTIFICATE-----
    - name: OPENSHIFT_DEPLOYMENT_NAME
      value: example-1
    - name: OPENSHIFT_DEPLOYMENT_NAMESPACE
      value: extended-test-cli-deployment-j4d8f-xwrkj
    image: openshift/origin-deployer:4762d6a
    imagePullPolicy: IfNotPresent
    name: deployment
    resources: {}
    securityContext:
      capabilities:
        drop:
        - KILL
        - MKNOD
        - SETGID
        - SETUID
      runAsUser: 1002350000
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
    volumeMounts:
    - mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      name: deployer-token-wszgz
      readOnly: true
  dnsPolicy: ClusterFirst
  imagePullSecrets:
  - name: deployer-dockercfg-v4kf9
  nodeName: ip-172-18-12-166.ec2.internal
  nodeSelector:
    region: infra
  restartPolicy: Never
  schedulerName: default-scheduler
  securityContext:
    fsGroup: 1002350000
    seLinuxOptions:
      level: s0:c48,c47
  serviceAccount: deployer
  serviceAccountName: deployer
  terminationGracePeriodSeconds: 10
  volumes:
  - name: deployer-token-wszgz
    secret:
      defaultMode: 420
      secretName: deployer-token-wszgz
status:
  conditions:
  - lastProbeTime: null
    lastTransitionTime: 2018-01-27T14:14:24Z
    status: "True"
    type: Initialized
  - lastProbeTime: null
    lastTransitionTime: 2018-01-27T14:14:24Z
    message: 'containers with unready status: [deployment]'
    reason: ContainersNotReady
    status: "False"
    type: Ready
  - lastProbeTime: null
    lastTransitionTime: 2018-01-27T14:14:24Z
    status: "True"
    type: PodScheduled
  containerStatuses:
  - image: openshift/origin-deployer:4762d6a
    imageID: ""
    lastState: {}
    name: deployment
    ready: false
    restartCount: 0
    state:
      waiting:
        message: Back-off pulling image "openshift/origin-deployer:4762d6a"
        reason: ImagePullBackOff
  hostIP: 172.18.12.166
  phase: Pending
  podIP: 10.128.1.69
  qosClass: BestEffort
  startTime: 2018-01-27T14:14:24Z

Jan 27 14:19:24.809: INFO: Running 'oc logs --config=/tmp/extended-test-cli-deployment-j4d8f-xwrkj-user.kubeconfig --namespace=extended-test-cli-deployment-j4d8f-xwrkj pod/example-1-deploy --timestamps=true'
Jan 27 14:19:25.061: INFO: Error running &{/data/src/github.com/openshift/origin/_output/local/bin/linux/amd64/oc [oc logs --config=/tmp/extended-test-cli-deployment-j4d8f-xwrkj-user.kubeconfig --namespace=extended-test-cli-deployment-j4d8f-xwrkj pod/example-1-deploy --timestamps=true] []   Error from server (BadRequest): container "deployment" in pod "example-1-deploy" is waiting to start: trying and failing to pull image
 Error from server (BadRequest): container "deployment" in pod "example-1-deploy" is waiting to start: trying and failing to pull image
 [] <nil> 0xc421701cb0 exit status 1 <nil> <nil> true [0xc4215547d8 0xc421554808 0xc421554808] [0xc4215547d8 0xc421554808] [0xc4215547e0 0xc4215547f8] [0x9895b0 0x9896b0] 0xc42169c120 <nil>}:
Error from server (BadRequest): container "deployment" in pod "example-1-deploy" is waiting to start: trying and failing to pull image
Jan 27 14:19:25.061: INFO: --- pod example-1-deploy logs
Error from server (BadRequest): container "deployment" in pod "example-1-deploy" is waiting to start: trying and failing to pull image---

[AfterEach] [Feature:DeploymentConfig] deploymentconfigs
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:62
[AfterEach] [Feature:DeploymentConfig] deploymentconfigs
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:135
STEP: Collecting events from namespace "extended-test-cli-deployment-j4d8f-xwrkj".
STEP: Found 8 events.
Jan 27 14:19:27.065: INFO: At 2018-01-27 14:14:24 +0000 UTC - event for example: {deploymentconfig-controller } DeploymentCreated: Created new replication controller "example-1" for version 1
Jan 27 14:19:27.065: INFO: At 2018-01-27 14:14:24 +0000 UTC - event for example-1-deploy: {default-scheduler } Scheduled: Successfully assigned example-1-deploy to ip-172-18-12-166.ec2.internal
Jan 27 14:19:27.065: INFO: At 2018-01-27 14:14:24 +0000 UTC - event for example-1-deploy: {kubelet ip-172-18-12-166.ec2.internal} SuccessfulMountVolume: MountVolume.SetUp succeeded for volume "deployer-token-wszgz" 
Jan 27 14:19:27.065: INFO: At 2018-01-27 14:14:26 +0000 UTC - event for example-1-deploy: {kubelet ip-172-18-12-166.ec2.internal} Pulling: pulling image "openshift/origin-deployer:4762d6a"
Jan 27 14:19:27.065: INFO: At 2018-01-27 14:14:26 +0000 UTC - event for example-1-deploy: {kubelet ip-172-18-12-166.ec2.internal} Failed: Failed to pull image "openshift/origin-deployer:4762d6a": rpc error: code = Unknown desc = manifest unknown: manifest unknown
Jan 27 14:19:27.065: INFO: At 2018-01-27 14:14:26 +0000 UTC - event for example-1-deploy: {kubelet ip-172-18-12-166.ec2.internal} Failed: Error: ErrImagePull
Jan 27 14:19:27.065: INFO: At 2018-01-27 14:14:27 +0000 UTC - event for example-1-deploy: {kubelet ip-172-18-12-166.ec2.internal} BackOff: Back-off pulling image "openshift/origin-deployer:4762d6a"
Jan 27 14:19:27.065: INFO: At 2018-01-27 14:14:27 +0000 UTC - event for example-1-deploy: {kubelet ip-172-18-12-166.ec2.internal} Failed: Error: ImagePullBackOff
Jan 27 14:19:27.072: INFO: POD                          NODE                           PHASE    GRACE  CONDITIONS
Jan 27 14:19:27.072: INFO: docker-registry-1-m9cd2      ip-172-18-12-166.ec2.internal  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:31:56 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:31:58 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:31:56 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: registry-console-1-nrrsw     ip-172-18-12-166.ec2.internal  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:32:18 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:32:35 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:32:18 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: router-1-rx6zp               ip-172-18-12-166.ec2.internal  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:31:40 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:31:51 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:31:40 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: mydockertest-1-build         ip-172-18-12-166.ec2.internal  Pending         [{Initialized False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:21:52 +0000 UTC ContainersNotInitialized containers with incomplete status: [git-clone manage-dockerfile]} {Ready False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:21:52 +0000 UTC ContainersNotReady containers with unready status: [docker-build]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:21:52 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: mys2itest-1-build            ip-172-18-12-166.ec2.internal  Pending         [{Initialized False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 14:10:23 +0000 UTC ContainersNotInitialized containers with incomplete status: [git-clone manage-dockerfile]} {Ready False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 14:10:23 +0000 UTC ContainersNotReady containers with unready status: [sti-build]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 14:10:23 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: sample-build-1-build         ip-172-18-12-166.ec2.internal  Pending         [{Initialized False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:20:32 +0000 UTC ContainersNotInitialized containers with incomplete status: [git-clone manage-dockerfile]} {Ready False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:20:32 +0000 UTC ContainersNotReady containers with unready status: [sti-build]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:20:32 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: example-1-deploy             ip-172-18-12-166.ec2.internal  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 14:14:24 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 14:14:24 +0000 UTC ContainersNotReady containers with unready status: [deployment]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 14:14:24 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: docker-build-1-build         ip-172-18-12-166.ec2.internal  Pending         [{Initialized False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:22:44 +0000 UTC ContainersNotInitialized containers with incomplete status: [manage-dockerfile]} {Ready False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:22:44 +0000 UTC ContainersNotReady containers with unready status: [docker-build]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 13:22:44 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: apiserver-v5k29              ip-172-18-12-166.ec2.internal  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:33:37 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:33:42 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:33:38 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: controller-manager-fgsqk     ip-172-18-12-166.ec2.internal  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:33:37 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:33:58 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:33:38 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: prometheus-0                 ip-172-18-12-166.ec2.internal  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:45:21 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:46:03 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:45:21 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: asb-1-deploy                 ip-172-18-12-166.ec2.internal  Failed          [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:07 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:44:10 +0000 UTC ContainersNotReady containers with unready status: [deployment]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:07 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: asb-etcd-1-deploy            ip-172-18-12-166.ec2.internal  Failed          [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:08 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:44:12 +0000 UTC ContainersNotReady containers with unready status: [deployment]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:08 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: apiserver-g7ltb              ip-172-18-12-166.ec2.internal  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:20 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:37 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:24 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: webconsole-69c864449c-tw8n9  ip-172-18-12-166.ec2.internal  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:49 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:35:01 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2018-01-27 11:34:49 +0000 UTC  }]
Jan 27 14:19:27.072: INFO: 
Jan 27 14:19:27.074: INFO: 
Logging node info for node ip-172-18-12-166.ec2.internal
Jan 27 14:19:27.076: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:ip-172-18-12-166.ec2.internal,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/ip-172-18-12-166.ec2.internal,UID:785e7c6b-0355-11e8-ba4b-0e7ab02740dc,ResourceVersion:42660,Generation:0,CreationTimestamp:2018-01-27 11:30:26 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{beta.kubernetes.io/arch: amd64,beta.kubernetes.io/os: linux,kubernetes.io/hostname: ip-172-18-12-166.ec2.internal,node-role.kubernetes.io/master: true,openshift-infra: apiserver,region: infra,registry: true,router: true,zone: default,},Annotations:map[string]string{volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,},Spec:NodeSpec{PodCIDR:,ExternalID:ip-172-18-12-166.ec2.internal,ProviderID:,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{cpu: {{4 0} {<nil>} 4 DecimalSI},memory: {{16656699392 0} {<nil>} 16266308Ki BinarySI},pods: {{40 0} {<nil>} 40 DecimalSI},},Allocatable:ResourceList{cpu: {{4 0} {<nil>} 4 DecimalSI},memory: {{16551841792 0} {<nil>} 16163908Ki BinarySI},pods: {{40 0} {<nil>} 40 DecimalSI},},Phase:,Conditions:[{OutOfDisk False 2018-01-27 14:19:19 +0000 UTC 2018-01-27 11:30:26 +0000 UTC KubeletHasSufficientDisk kubelet has sufficient disk space available} {MemoryPressure False 2018-01-27 14:19:19 +0000 UTC 2018-01-27 11:30:26 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2018-01-27 14:19:19 +0000 UTC 2018-01-27 12:03:45 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {Ready True 2018-01-27 14:19:19 +0000 UTC 2018-01-27 11:31:08 +0000 UTC KubeletReady kubelet is posting ready status}],Addresses:[{InternalIP 172.18.12.166} {Hostname ip-172-18-12-166.ec2.internal}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:4372f1e2f8c642d3a2f3ed11aa3fe654,SystemUUID:EC215B86-AE12-2D5A-4C86-79FE72AD3649,BootID:1e42fcc7-c01c-4b86-baf6-44f7f44860bc,KernelVersion:3.10.0-693.17.1.el7.x86_64,OSImage:Red Hat Enterprise Linux Server 7.4 (Maipo),ContainerRuntimeVersion:cri-o://1.9.2-dev,KubeletVersion:v1.9.1+a0ce1bc657,KubeProxyVersion:v1.9.1+a0ce1bc657,OperatingSystem:linux,Architecture:amd64,},Images:[{[docker.io/openshift/origin-haproxy-router:4762d6a] 1279509128} {[docker.io/centos/nodejs-6-centos7:latest] 515826975} {[docker.io/centos/mongodb-34-centos7:latest] 507285392} {[docker.io/openshift/origin-web-console:latest] 501206984} {[docker.io/openshift/origin-docker-registry:4762d6a] 466450956} {[docker.io/centos/mysql-57-centos7:latest] 447153977} {[docker.io/cockpit/kubernetes:latest] 399544576} {[docker.io/openshift/origin-template-service-broker:latest] 313282745} {[docker.io/openshift/origin-service-catalog:latest] 287397545} {[docker.io/openshift/prometheus:v2.0.0] 275096478} {[docker.io/openshift/origin-pod:latest] 228579489} {[docker.io/openshift/origin-pod:4762d6a] 228579292} {[docker.io/openshift/oauth-proxy:v1.0.0] 228244754} {[docker.io/openshift/prometheus-alertmanager:v0.9.1] 220898782} {[docker.io/openshift/prometheus-alert-buffer:v0.0.2] 200523944} {[docker.io/library/nginx:latest] 108499054} {[gcr.io/google-containers/nginx-slim-amd64:0.20] 103595087} {[gcr.io/google_containers/dnsutils:e2e] 8901417} {[gcr.io/kubernetes-e2e-test-images/hostexec-amd64:1.0] 8377623} {[gcr.io/kubernetes-e2e-test-images/netexec-amd64:1.0] 6230968} {[gcr.io/kubernetes-e2e-test-images/serve-hostname-amd64:1.0] 5472826} {[gcr.io/kubernetes-e2e-test-images/test-webserver-amd64:1.0] 4396136} {[gcr.io/kubernetes-e2e-test-images/liveness-amd64:1.0] 4281457} {[gcr.io/google_containers/busybox:latest] 2439416} {[gcr.io/kubernetes-e2e-test-images/mounttest-user-amd64:1.0] 1452588} {[gcr.io/kubernetes-e2e-test-images/mounttest-amd64:1.0] 1452489} {[] 1148393} {[docker.io/library/busybox:latest] 1148393} {[gcr.io/google_containers/pause-amd64:3.0] 751477} {[docker.io/kubernetes/pause:latest] 246793}],VolumesInUse:[],VolumesAttached:[],},}
Jan 27 14:19:27.076: INFO: 
Logging kubelet events for node ip-172-18-12-166.ec2.internal
Jan 27 14:19:27.078: INFO: 
Logging pods the kubelet thinks is on node ip-172-18-12-166.ec2.internal
Jan 27 14:19:27.087: INFO: apiserver-g7ltb started at 2018-01-27 11:34:20 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container c ready: true, restart count 0
Jan 27 14:19:27.087: INFO: asb-1-deploy started at 2018-01-27 11:34:07 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container deployment ready: false, restart count 0
Jan 27 14:19:27.087: INFO: webconsole-69c864449c-tw8n9 started at 2018-01-27 11:34:49 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container webconsole ready: true, restart count 0
Jan 27 14:19:27.087: INFO: mydockertest-1-build started at 2018-01-27 13:21:52 +0000 UTC (2+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Init container git-clone ready: false, restart count 0
Jan 27 14:19:27.087: INFO: 	Init container manage-dockerfile ready: false, restart count 0
Jan 27 14:19:27.087: INFO: 	Container docker-build ready: false, restart count 0
Jan 27 14:19:27.087: INFO: controller-manager-fgsqk started at 2018-01-27 11:33:37 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container controller-manager ready: true, restart count 2
Jan 27 14:19:27.087: INFO: docker-build-1-build started at 2018-01-27 13:22:44 +0000 UTC (1+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Init container manage-dockerfile ready: false, restart count 0
Jan 27 14:19:27.087: INFO: 	Container docker-build ready: false, restart count 0
Jan 27 14:19:27.087: INFO: router-1-rx6zp started at 2018-01-27 11:31:40 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container router ready: true, restart count 0
Jan 27 14:19:27.087: INFO: asb-etcd-1-deploy started at 2018-01-27 11:34:08 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container deployment ready: false, restart count 0
Jan 27 14:19:27.087: INFO: prometheus-0 started at 2018-01-27 11:45:21 +0000 UTC (0+6 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container alert-buffer ready: true, restart count 0
Jan 27 14:19:27.087: INFO: 	Container alertmanager ready: true, restart count 0
Jan 27 14:19:27.087: INFO: 	Container alertmanager-proxy ready: true, restart count 0
Jan 27 14:19:27.087: INFO: 	Container alerts-proxy ready: true, restart count 0
Jan 27 14:19:27.087: INFO: 	Container prom-proxy ready: true, restart count 0
Jan 27 14:19:27.087: INFO: 	Container prometheus ready: true, restart count 0
Jan 27 14:19:27.087: INFO: registry-console-1-nrrsw started at 2018-01-27 11:32:18 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container registry-console ready: true, restart count 0
Jan 27 14:19:27.087: INFO: docker-registry-1-m9cd2 started at 2018-01-27 11:31:56 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container registry ready: true, restart count 0
Jan 27 14:19:27.087: INFO: apiserver-v5k29 started at 2018-01-27 11:33:37 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container apiserver ready: true, restart count 0
Jan 27 14:19:27.087: INFO: sample-build-1-build started at 2018-01-27 13:20:32 +0000 UTC (2+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Init container git-clone ready: false, restart count 0
Jan 27 14:19:27.087: INFO: 	Init container manage-dockerfile ready: false, restart count 0
Jan 27 14:19:27.087: INFO: 	Container sti-build ready: false, restart count 0
Jan 27 14:19:27.087: INFO: mys2itest-1-build started at 2018-01-27 14:10:23 +0000 UTC (2+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Init container git-clone ready: false, restart count 0
Jan 27 14:19:27.087: INFO: 	Init container manage-dockerfile ready: false, restart count 0
Jan 27 14:19:27.087: INFO: 	Container sti-build ready: false, restart count 0
Jan 27 14:19:27.087: INFO: example-1-deploy started at 2018-01-27 14:14:24 +0000 UTC (0+1 container statuses recorded)
Jan 27 14:19:27.087: INFO: 	Container deployment ready: false, restart count 0
W0127 14:19:27.090149   76271 metrics_grabber.go:81] Master node is not registered. Grabbing metrics from Scheduler, ControllerManager and ClusterAutoscaler is disabled.
Jan 27 14:19:27.113: INFO: 
Latency metrics for node ip-172-18-12-166.ec2.internal
Jan 27 14:19:27.113: INFO: {Operation:create Method:pod_worker_latency_microseconds Quantile:0.99 Latency:2m3.025489s}
Jan 27 14:19:27.113: INFO: {Operation:create Method:pod_worker_latency_microseconds Quantile:0.9 Latency:2m3.025489s}
STEP: Dumping a list of prepulled images on each node...
Jan 27 14:19:27.115: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "extended-test-cli-deployment-j4d8f-xwrkj" for this suite.
Jan 27 14:19:39.128: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
Jan 27 14:19:39.204: INFO: namespace: extended-test-cli-deployment-j4d8f-xwrkj, resource: bindings, ignored listing per whitelist
Jan 27 14:19:39.290: INFO: namespace extended-test-cli-deployment-j4d8f-xwrkj deletion completed in 12.17237357s


• Failure [315.643 seconds]
[Feature:DeploymentConfig] deploymentconfigs
/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:37
  won't deploy RC with unresolved images [Conformance]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:1398
    when patched with empty image [Suite:openshift/conformance/parallel] [It]
    /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:1405

    Expected error:
        <*errors.errorString | 0xc4202cfd40>: {
            s: "timed out waiting for the condition",
        }
        timed out waiting for the condition
    not to have occurred

    /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:1437
@tnozicka tnozicka added priority/P1 area/tests kind/test-flake Categorizes issue or PR as related to test flakes. labels Jan 31, 2018
@runcom
Copy link
Member

runcom commented Jan 31, 2018

This is because the image is being removed by the image GC. We're working with @stevekuznetsov to upgrade disk size on CFI-O instances to fix the issue.

@tnozicka
Copy link
Contributor Author

@runcom is that also the reason why it doesn't get pulled again? The test is waiting for 5 minutes on the pull.

/assign @runcom @stevekuznetsov

@runcom
Copy link
Member

runcom commented Jan 31, 2018

@runcom is that also the reason why it doesn't get pulled again? The test is waiting for 5 minutes on the pull.

yes, that images can't be pulled, it's built as part of the whole test so that's why it's failing to pull it.

@tnozicka
Copy link
Contributor Author

makes sense, thx for explaining it ;)

@runcom
Copy link
Member

runcom commented Feb 12, 2018

Fixed by increasing disk size of test instances

@runcom runcom closed this as completed Feb 12, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@runcom runcom

@stevekuznetsov stevekuznetsov

Labels
area/tests kind/test-flake Categorizes issue or PR as related to test flakes. priority/P1
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@runcom @stevekuznetsov @tnozicka