[Conformance] deploymentconfigs with custom deployments should run the custom deployment steps flakes #17631

php-coder · 2017-12-06T15:10:55Z

Seen here: https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/17606/test_pull_request_origin_extended_conformance_gce/12465/

A full log:

[Feature:DeploymentConfig] deploymentconfigs with custom deployments [Conformance] 
  should run the custom deployment steps [Suite:openshift/conformance/parallel]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:563

[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
  /tmp/openshift/build-rpms/rpm/BUILD/origin-3.9.0/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:137
STEP: Creating a kubernetes client
Dec  6 13:14:59.343: INFO: >>> kubeConfig: /tmp/cluster-admin.kubeconfig
STEP: Building a namespace api object
Dec  6 13:14:59.483: INFO: configPath is now "/tmp/extended-test-cli-deployment-h94tt-x597n-user.kubeconfig"
Dec  6 13:14:59.483: INFO: The user is now "extended-test-cli-deployment-h94tt-x597n-user"
Dec  6 13:14:59.483: INFO: Creating project "extended-test-cli-deployment-h94tt-x597n"
Dec  6 13:14:59.577: INFO: Waiting on permissions in project "extended-test-cli-deployment-h94tt-x597n" ...
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:57
[It] should run the custom deployment steps [Suite:openshift/conformance/parallel]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:563
Dec  6 13:14:59.669: INFO: Running 'oc create --config=/tmp/extended-test-cli-deployment-h94tt-x597n-user.kubeconfig --namespace=extended-test-cli-deployment-h94tt-x597n -f /tmp/fixture-testdata-dir919063928/test/extended/testdata/deployments/custom-deployment.yaml'
Dec  6 13:15:32.287: INFO: Running 'oc deploy --config=/tmp/extended-test-cli-deployment-h94tt-x597n-user.kubeconfig --namespace=extended-test-cli-deployment-h94tt-x597n --follow dc/custom-deployment'
STEP: verifying the deployment is marked complete
Dec  6 13:15:32.634: INFO: Latest rollout of dc/custom-deployment (rc/custom-deployment-1) is complete.
STEP: checking the logs for substrings
Command "deploy" is deprecated, Use the `rollout latest` and `rollout cancel` commands instead.
[AfterEach] with custom deployments [Conformance]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:538
Dec  6 13:15:32.634: INFO: Running 'oc get --config=/tmp/extended-test-cli-deployment-h94tt-x597n-user.kubeconfig --namespace=extended-test-cli-deployment-h94tt-x597n dc/custom-deployment -o yaml'
Dec  6 13:15:32.909: INFO: 
apiVersion: v1
kind: DeploymentConfig
metadata:
  creationTimestamp: 2017-12-06T13:14:59Z
  generation: 1
  name: custom-deployment
  namespace: extended-test-cli-deployment-h94tt-x597n
  resourceVersion: "10315"
  selfLink: /oapi/v1/namespaces/extended-test-cli-deployment-h94tt-x597n/deploymentconfigs/custom-deployment
  uid: 76607110-da87-11e7-ae30-42010a8e0005
spec:
  replicas: 2
  selector:
    name: custom-deployment
  strategy:
    activeDeadlineSeconds: 21600
    customParams:
      command:
      - /bin/sh
      - -c
      - |
        set -e
        openshift-deploy --until=50%
        echo Halfway
        openshift-deploy
        echo Finished
        sleep 1
    resources: {}
    rollingParams:
      intervalSeconds: 1
      maxSurge: 25%
      maxUnavailable: 25%
      pre:
        execNewPod:
          command:
          - /bin/echo
          - test pre hook executed
          containerName: myapp
        failurePolicy: Abort
      timeoutSeconds: 600
      updatePeriodSeconds: 1
    type: Rolling
  template:
    metadata:
      creationTimestamp: null
      labels:
        name: custom-deployment
    spec:
      containers:
      - command:
        - /bin/sleep
        - "10"
        image: docker.io/centos:centos7
        imagePullPolicy: IfNotPresent
        name: myapp
        resources: {}
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
      dnsPolicy: ClusterFirst
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext: {}
      terminationGracePeriodSeconds: 0
  test: false
  triggers:
  - type: ConfigChange
status:
  availableReplicas: 0
  conditions:
  - lastTransitionTime: 2017-12-06T13:15:30Z
    lastUpdateTime: 2017-12-06T13:15:30Z
    message: Deployment config does not have minimum availability.
    status: "False"
    type: Available
  - lastTransitionTime: 2017-12-06T13:15:32Z
    lastUpdateTime: 2017-12-06T13:15:32Z
    message: replication controller "custom-deployment-1" successfully rolled out
    reason: NewReplicationControllerAvailable
    status: "True"
    type: Progressing
  details:
    causes:
    - type: ConfigChange
    message: config change
  latestVersion: 1
  observedGeneration: 1
  replicas: 2
  unavailableReplicas: 2
  updatedReplicas: 2

Dec  6 13:15:32.961: INFO: Running 'oc get --config=/tmp/extended-test-cli-deployment-h94tt-x597n-user.kubeconfig --namespace=extended-test-cli-deployment-h94tt-x597n rc/custom-deployment-1 -o yaml'
Dec  6 13:15:33.221: INFO: 
apiVersion: v1
kind: ReplicationController
metadata:
  annotations:
    openshift.io/deployer-pod.completed-at: 2017-12-06 13:15:22 +0000 UTC
    openshift.io/deployer-pod.created-at: 2017-12-06 13:14:59 +0000 UTC
    openshift.io/deployer-pod.name: custom-deployment-1-deploy
    openshift.io/deployment-config.latest-version: "1"
    openshift.io/deployment-config.name: custom-deployment
    openshift.io/deployment.phase: Complete
    openshift.io/deployment.replicas: "2"
    openshift.io/deployment.status-reason: config change
    openshift.io/encoded-deployment-config: |
      {"kind":"DeploymentConfig","apiVersion":"v1","metadata":{"name":"custom-deployment","namespace":"extended-test-cli-deployment-h94tt-x597n","selfLink":"/apis/apps.openshift.io/v1/namespaces/extended-test-cli-deployment-h94tt-x597n/deploymentconfigs/custom-deployment","uid":"76607110-da87-11e7-ae30-42010a8e0005","resourceVersion":"8998","generation":1,"creationTimestamp":"2017-12-06T13:14:59Z"},"spec":{"strategy":{"type":"Rolling","customParams":{"command":["/bin/sh","-c","set -e\nopenshift-deploy --until=50%\necho Halfway\nopenshift-deploy\necho Finished\nsleep 1\n"]},"rollingParams":{"updatePeriodSeconds":1,"intervalSeconds":1,"timeoutSeconds":600,"maxUnavailable":"25%","maxSurge":"25%","pre":{"failurePolicy":"Abort","execNewPod":{"command":["/bin/echo","test pre hook executed"],"containerName":"myapp"}}},"resources":{},"activeDeadlineSeconds":21600},"triggers":[{"type":"ConfigChange"}],"replicas":2,"test":false,"selector":{"name":"custom-deployment"},"template":{"metadata":{"creationTimestamp":null,"labels":{"name":"custom-deployment"}},"spec":{"containers":[{"name":"myapp","image":"docker.io/centos:centos7","command":["/bin/sleep","10"],"resources":{},"terminationMessagePath":"/dev/termination-log","terminationMessagePolicy":"File","imagePullPolicy":"IfNotPresent"}],"restartPolicy":"Always","terminationGracePeriodSeconds":0,"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":"2017-12-06T13:14:59Z","lastTransitionTime":"2017-12-06T13:14:59Z","message":"Deployment config does not have minimum availability."}]}}
  creationTimestamp: 2017-12-06T13:14:59Z
  generation: 2
  labels:
    openshift.io/deployment-config.name: custom-deployment
  name: custom-deployment-1
  namespace: extended-test-cli-deployment-h94tt-x597n
  ownerReferences:
  - apiVersion: apps.openshift.io/v1
    blockOwnerDeletion: true
    controller: true
    kind: DeploymentConfig
    name: custom-deployment
    uid: 76607110-da87-11e7-ae30-42010a8e0005
  resourceVersion: "10314"
  selfLink: /api/v1/namespaces/extended-test-cli-deployment-h94tt-x597n/replicationcontrollers/custom-deployment-1
  uid: 76632bb7-da87-11e7-ae30-42010a8e0005
spec:
  replicas: 2
  selector:
    deployment: custom-deployment-1
    deploymentconfig: custom-deployment
    name: custom-deployment
  template:
    metadata:
      annotations:
        openshift.io/deployment-config.latest-version: "1"
        openshift.io/deployment-config.name: custom-deployment
        openshift.io/deployment.name: custom-deployment-1
      creationTimestamp: null
      labels:
        deployment: custom-deployment-1
        deploymentconfig: custom-deployment
        name: custom-deployment
    spec:
      containers:
      - command:
        - /bin/sleep
        - "10"
        image: docker.io/centos:centos7
        imagePullPolicy: IfNotPresent
        name: myapp
        resources: {}
        terminationMessagePath: /dev/termination-log
        terminationMessagePolicy: File
      dnsPolicy: ClusterFirst
      restartPolicy: Always
      schedulerName: default-scheduler
      securityContext: {}
      terminationGracePeriodSeconds: 0
status:
  fullyLabeledReplicas: 2
  observedGeneration: 2
  replicas: 2

Dec  6 13:15:33.221: INFO: Running 'oc get --config=/tmp/extended-test-cli-deployment-h94tt-x597n-user.kubeconfig --namespace=extended-test-cli-deployment-h94tt-x597n pod/custom-deployment-1-qj7q9 -o yaml'
Dec  6 13:15:33.486: INFO: 
apiVersion: v1
kind: Pod
metadata:
  annotations:
    kubernetes.io/created-by: |
      {"kind":"SerializedReference","apiVersion":"v1","reference":{"kind":"ReplicationController","namespace":"extended-test-cli-deployment-h94tt-x597n","name":"custom-deployment-1","uid":"76632bb7-da87-11e7-ae30-42010a8e0005","apiVersion":"v1","resourceVersion":"9425"}}
    openshift.io/deployment-config.latest-version: "1"
    openshift.io/deployment-config.name: custom-deployment
    openshift.io/deployment.name: custom-deployment-1
    openshift.io/scc: restricted
  creationTimestamp: 2017-12-06T13:15:07Z
  generateName: custom-deployment-1-
  labels:
    deployment: custom-deployment-1
    deploymentconfig: custom-deployment
    name: custom-deployment
  name: custom-deployment-1-qj7q9
  namespace: extended-test-cli-deployment-h94tt-x597n
  ownerReferences:
  - apiVersion: v1
    blockOwnerDeletion: true
    controller: true
    kind: ReplicationController
    name: custom-deployment-1
    uid: 76632bb7-da87-11e7-ae30-42010a8e0005
  resourceVersion: "10218"
  selfLink: /api/v1/namespaces/extended-test-cli-deployment-h94tt-x597n/pods/custom-deployment-1-qj7q9
  uid: 7ada9895-da87-11e7-ae30-42010a8e0005
spec:
  containers:
  - command:
    - /bin/sleep
    - "10"
    image: docker.io/centos:centos7
    imagePullPolicy: IfNotPresent
    name: myapp
    resources: {}
    securityContext:
      capabilities:
        drop:
        - KILL
        - MKNOD
        - SETGID
        - SETUID
      privileged: false
      runAsUser: 1000970000
      seLinuxOptions:
        level: s0:c31,c20
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
    volumeMounts:
    - mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      name: default-token-2krnp
      readOnly: true
  dnsPolicy: ClusterFirst
  imagePullSecrets:
  - name: default-dockercfg-h8n64
  nodeName: ci-prtest-5a37c28-12465-ig-n-m4h4
  nodeSelector:
    role: app
  restartPolicy: Always
  schedulerName: default-scheduler
  securityContext:
    fsGroup: 1000970000
    seLinuxOptions:
      level: s0:c31,c20
  serviceAccount: default
  serviceAccountName: default
  terminationGracePeriodSeconds: 0
  volumes:
  - name: default-token-2krnp
    secret:
      defaultMode: 420
      secretName: default-token-2krnp
status:
  conditions:
  - lastProbeTime: null
    lastTransitionTime: 2017-12-06T13:15:07Z
    status: "True"
    type: Initialized
  - lastProbeTime: null
    lastTransitionTime: 2017-12-06T13:15:31Z
    message: 'containers with unready status: [myapp]'
    reason: ContainersNotReady
    status: "False"
    type: Ready
  - lastProbeTime: null
    lastTransitionTime: 2017-12-06T13:15:07Z
    status: "True"
    type: PodScheduled
  containerStatuses:
  - containerID: docker://77425a8147e47269c857bd5a0a8e4e53525070406172042f05199e80df411b16
    image: docker.io/centos:centos7
    imageID: docker-pullable://docker.io/centos@sha256:3b1a65e9a05f0a77b5e8a698d3359459904c2a354dc3b25ae2e2f5c95f0b3667
    lastState: {}
    name: myapp
    ready: false
    restartCount: 0
    state:
      terminated:
        containerID: docker://77425a8147e47269c857bd5a0a8e4e53525070406172042f05199e80df411b16
        exitCode: 0
        finishedAt: 2017-12-06T13:15:21Z
        reason: Completed
        startedAt: 2017-12-06T13:15:11Z
  hostIP: 10.142.0.2
  phase: Running
  podIP: 172.16.2.53
  qosClass: BestEffort
  startTime: 2017-12-06T13:15:07Z

Dec  6 13:15:33.486: INFO: Running 'oc get --config=/tmp/extended-test-cli-deployment-h94tt-x597n-user.kubeconfig --namespace=extended-test-cli-deployment-h94tt-x597n pod/custom-deployment-1-r9wpm -o yaml'
Dec  6 13:15:33.736: INFO: 
apiVersion: v1
kind: Pod
metadata:
  annotations:
    kubernetes.io/created-by: |
      {"kind":"SerializedReference","apiVersion":"v1","reference":{"kind":"ReplicationController","namespace":"extended-test-cli-deployment-h94tt-x597n","name":"custom-deployment-1","uid":"76632bb7-da87-11e7-ae30-42010a8e0005","apiVersion":"v1","resourceVersion":"9425"}}
    openshift.io/deployment-config.latest-version: "1"
    openshift.io/deployment-config.name: custom-deployment
    openshift.io/deployment.name: custom-deployment-1
    openshift.io/scc: restricted
  creationTimestamp: 2017-12-06T13:15:07Z
  generateName: custom-deployment-1-
  labels:
    deployment: custom-deployment-1
    deploymentconfig: custom-deployment
    name: custom-deployment
  name: custom-deployment-1-r9wpm
  namespace: extended-test-cli-deployment-h94tt-x597n
  ownerReferences:
  - apiVersion: v1
    blockOwnerDeletion: true
    controller: true
    kind: ReplicationController
    name: custom-deployment-1
    uid: 76632bb7-da87-11e7-ae30-42010a8e0005
  resourceVersion: "10213"
  selfLink: /api/v1/namespaces/extended-test-cli-deployment-h94tt-x597n/pods/custom-deployment-1-r9wpm
  uid: 7ad90858-da87-11e7-ae30-42010a8e0005
spec:
  containers:
  - command:
    - /bin/sleep
    - "10"
    image: docker.io/centos:centos7
    imagePullPolicy: IfNotPresent
    name: myapp
    resources: {}
    securityContext:
      capabilities:
        drop:
        - KILL
        - MKNOD
        - SETGID
        - SETUID
      privileged: false
      runAsUser: 1000970000
      seLinuxOptions:
        level: s0:c31,c20
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
    volumeMounts:
    - mountPath: /var/run/secrets/kubernetes.io/serviceaccount
      name: default-token-2krnp
      readOnly: true
  dnsPolicy: ClusterFirst
  imagePullSecrets:
  - name: default-dockercfg-h8n64
  nodeName: ci-prtest-5a37c28-12465-ig-n-r9qb
  nodeSelector:
    role: app
  restartPolicy: Always
  schedulerName: default-scheduler
  securityContext:
    fsGroup: 1000970000
    seLinuxOptions:
      level: s0:c31,c20
  serviceAccount: default
  serviceAccountName: default
  terminationGracePeriodSeconds: 0
  volumes:
  - name: default-token-2krnp
    secret:
      defaultMode: 420
      secretName: default-token-2krnp
status:
  conditions:
  - lastProbeTime: null
    lastTransitionTime: 2017-12-06T13:15:07Z
    status: "True"
    type: Initialized
  - lastProbeTime: null
    lastTransitionTime: 2017-12-06T13:15:30Z
    message: 'containers with unready status: [myapp]'
    reason: ContainersNotReady
    status: "False"
    type: Ready
  - lastProbeTime: null
    lastTransitionTime: 2017-12-06T13:15:07Z
    status: "True"
    type: PodScheduled
  containerStatuses:
  - containerID: docker://8710fec26acba02b32c5fb18a392ef26a649a970c561df5aa6b58a401ae4c56a
    image: docker.io/centos:centos7
    imageID: docker-pullable://docker.io/centos@sha256:3b1a65e9a05f0a77b5e8a698d3359459904c2a354dc3b25ae2e2f5c95f0b3667
    lastState:
      terminated:
        containerID: docker://a048b40bcb2f147b6fd7a0700b309c7a3122e38c74835a47743a3ee37ebed07c
        exitCode: 0
        finishedAt: 2017-12-06T13:15:18Z
        reason: Completed
        startedAt: 2017-12-06T13:15:08Z
    name: myapp
    ready: false
    restartCount: 1
    state:
      terminated:
        containerID: docker://8710fec26acba02b32c5fb18a392ef26a649a970c561df5aa6b58a401ae4c56a
        exitCode: 0
        finishedAt: 2017-12-06T13:15:29Z
        reason: Completed
        startedAt: 2017-12-06T13:15:19Z
  hostIP: 10.142.0.3
  phase: Running
  podIP: 172.16.0.32
  qosClass: BestEffort
  startTime: 2017-12-06T13:15:07Z

[AfterEach] [Feature:DeploymentConfig] deploymentconfigs
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:75
[AfterEach] [Feature:DeploymentConfig] deploymentconfigs
  /tmp/openshift/build-rpms/rpm/BUILD/origin-3.9.0/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:138
STEP: Collecting events from namespace "extended-test-cli-deployment-h94tt-x597n".
STEP: Found 29 events.
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:14:59 +0000 UTC - event for custom-deployment: {deploymentconfig-controller } DeploymentCreated: Created new replication controller "custom-deployment-1" for version 1
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:14:59 +0000 UTC - event for custom-deployment-1-deploy: {default-scheduler } Scheduled: Successfully assigned custom-deployment-1-deploy to ci-prtest-5a37c28-12465-ig-n-5rlb
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:01 +0000 UTC - event for custom-deployment-1-deploy: {kubelet ci-prtest-5a37c28-12465-ig-n-5rlb} SuccessfulMountVolume: MountVolume.SetUp succeeded for volume "deployer-token-vbtq2" 
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:03 +0000 UTC - event for custom-deployment-1-deploy: {kubelet ci-prtest-5a37c28-12465-ig-n-5rlb} Pulled: Container image "openshift/origin-deployer:v3.9.0-alpha.0" already present on machine
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:04 +0000 UTC - event for custom-deployment-1-deploy: {kubelet ci-prtest-5a37c28-12465-ig-n-5rlb} Created: Created container
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:05 +0000 UTC - event for custom-deployment: {custom-deployment-1-deploy } Started: Running pre-hook ("/bin/echo test pre hook executed") for rc extended-test-cli-deployment-h94tt-x597n/custom-deployment-1
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:05 +0000 UTC - event for custom-deployment-1-deploy: {kubelet ci-prtest-5a37c28-12465-ig-n-5rlb} Started: Started container
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:05 +0000 UTC - event for custom-deployment-1-hook-pre: {default-scheduler } Scheduled: Successfully assigned custom-deployment-1-hook-pre to ci-prtest-5a37c28-12465-ig-n-r9qb
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:05 +0000 UTC - event for custom-deployment-1-hook-pre: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} SuccessfulMountVolume: MountVolume.SetUp succeeded for volume "default-token-2krnp" 
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:06 +0000 UTC - event for custom-deployment-1-hook-pre: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} Created: Created container
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:06 +0000 UTC - event for custom-deployment-1-hook-pre: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} Started: Started container
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:06 +0000 UTC - event for custom-deployment-1-hook-pre: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} Pulled: Container image "docker.io/centos:centos7" already present on machine
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:07 +0000 UTC - event for custom-deployment: {custom-deployment-1-deploy } Completed: The pre-hook for rc extended-test-cli-deployment-h94tt-x597n/custom-deployment-1 completed successfully
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:07 +0000 UTC - event for custom-deployment-1: {replication-controller } SuccessfulCreate: Created pod: custom-deployment-1-qj7q9
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:07 +0000 UTC - event for custom-deployment-1: {replication-controller } SuccessfulCreate: Created pod: custom-deployment-1-r9wpm
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:07 +0000 UTC - event for custom-deployment-1-qj7q9: {default-scheduler } Scheduled: Successfully assigned custom-deployment-1-qj7q9 to ci-prtest-5a37c28-12465-ig-n-m4h4
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:07 +0000 UTC - event for custom-deployment-1-r9wpm: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} SuccessfulMountVolume: MountVolume.SetUp succeeded for volume "default-token-2krnp" 
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:07 +0000 UTC - event for custom-deployment-1-r9wpm: {default-scheduler } Scheduled: Successfully assigned custom-deployment-1-r9wpm to ci-prtest-5a37c28-12465-ig-n-r9qb
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:08 +0000 UTC - event for custom-deployment-1-hook-pre: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} SandboxChanged: Pod sandbox changed, it will be killed and re-created.
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:08 +0000 UTC - event for custom-deployment-1-qj7q9: {kubelet ci-prtest-5a37c28-12465-ig-n-m4h4} SuccessfulMountVolume: MountVolume.SetUp succeeded for volume "default-token-2krnp" 
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:08 +0000 UTC - event for custom-deployment-1-r9wpm: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} Pulled: Container image "docker.io/centos:centos7" already present on machine
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:08 +0000 UTC - event for custom-deployment-1-r9wpm: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} Created: Created container
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:08 +0000 UTC - event for custom-deployment-1-r9wpm: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} Started: Started container
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:10 +0000 UTC - event for custom-deployment-1-qj7q9: {kubelet ci-prtest-5a37c28-12465-ig-n-m4h4} Created: Created container
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:10 +0000 UTC - event for custom-deployment-1-qj7q9: {kubelet ci-prtest-5a37c28-12465-ig-n-m4h4} Pulled: Container image "docker.io/centos:centos7" already present on machine
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:12 +0000 UTC - event for custom-deployment-1-qj7q9: {kubelet ci-prtest-5a37c28-12465-ig-n-m4h4} Started: Started container
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:19 +0000 UTC - event for custom-deployment: {custom-deployment-1-deploy } Started: Running pre-hook ("/bin/echo test pre hook executed") for rc extended-test-cli-deployment-h94tt-x597n/custom-deployment-1
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:19 +0000 UTC - event for custom-deployment: {custom-deployment-1-deploy } Completed: The pre-hook for rc extended-test-cli-deployment-h94tt-x597n/custom-deployment-1 completed successfully
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:31 +0000 UTC - event for custom-deployment-1-r9wpm: {kubelet ci-prtest-5a37c28-12465-ig-n-r9qb} BackOff: Back-off restarting failed container
Dec  6 13:15:35.831: INFO: POD                                                      NODE                               PHASE      GRACE  CONDITIONS
Dec  6 13:15:35.831: INFO: docker-registry-1-vww25                                  ci-prtest-5a37c28-12465-ig-m-lq53  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:12:49 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:06 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:12:49 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: registry-console-1-vjcxx                                 ci-prtest-5a37c28-12465-ig-n-r9qb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:12:52 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:27 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:12:52 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: router-1-wcctt                                           ci-prtest-5a37c28-12465-ig-m-lq53  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:12:50 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:21 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:12:50 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: liveness-exec                                            ci-prtest-5a37c28-12465-ig-n-m4h4  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:13 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:37 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:13 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: test-webserver-896c3786-da87-11e7-a5ed-0e9fdaedd9a2      ci-prtest-5a37c28-12465-ig-n-5rlb  Pending           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:32 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:32 +0000 UTC ContainersNotReady containers with unready status: [test-webserver]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:31 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: pod-init-735d02e3-da87-11e7-9c89-0e9fdaedd9a2            ci-prtest-5a37c28-12465-ig-n-m4h4  Succeeded         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:26 +0000 UTC PodCompleted } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:54 +0000 UTC PodCompleted } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:54 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: isolation-webserver                                      ci-prtest-5a37c28-12465-ig-n-5rlb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:00 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:33 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: execpod-sourceip-ci-prtest-5a37c28-12465-ig-n-5rlbg6hpk  ci-prtest-5a37c28-12465-ig-n-5rlb  Pending           []
Dec  6 13:15:35.831: INFO: service-scrck                                            ci-prtest-5a37c28-12465-ig-n-5rlb  Failed     30s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:13 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:14 +0000 UTC ContainersNotReady containers with unready status: [service-scrck-container]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:32 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: annotationupdate778b4425-da87-11e7-bb0b-0e9fdaedd9a2     ci-prtest-5a37c28-12465-ig-n-5rlb  Pending           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:01 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:01 +0000 UTC ContainersNotReady containers with unready status: [client-container]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:01 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: myphp-1-build                                            ci-prtest-5a37c28-12465-ig-n-r9qb  Succeeded         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:53 +0000 UTC PodCompleted } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:32 +0000 UTC PodCompleted } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:34 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: myphp-2-build                                            ci-prtest-5a37c28-12465-ig-n-m4h4  Succeeded         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:41 +0000 UTC PodCompleted } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:35 +0000 UTC PodCompleted } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:35 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: mydockertest-1-build                                     ci-prtest-5a37c28-12465-ig-n-5rlb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:17 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:18 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:02 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: custom-deployment-1-qj7q9                                ci-prtest-5a37c28-12465-ig-n-m4h4  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:07 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:34 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:07 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: custom-deployment-1-r9wpm                                ci-prtest-5a37c28-12465-ig-n-r9qb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:07 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:30 +0000 UTC ContainersNotReady containers with unready status: [myapp]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:07 +0000 UTC  }]
Dec  6 13:15:35.831: INFO: history-limit-2-jncx5                                    ci-prtest-5a37c28-12465-ig-n-5rlb  Running    30s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:59 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:25 +0000 UTC ContainersNotReady containers with unready status: [myapp]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:59 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: history-limit-5-tssv5                                    ci-prtest-5a37c28-12465-ig-n-r9qb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:46 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:48 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:46 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: history-limit-6-695mh                                    ci-prtest-5a37c28-12465-ig-n-5rlb  Pending           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:01 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:01 +0000 UTC ContainersNotReady containers with unready status: [myapp]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:01 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: history-limit-6-deploy                                   ci-prtest-5a37c28-12465-ig-n-5rlb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:52 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:35 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:52 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: example-1-deploy                                         ci-prtest-5a37c28-12465-ig-n-r9qb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:23 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:24 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:23 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: example-1-t9qwv                                          ci-prtest-5a37c28-12465-ig-n-m4h4  Pending           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:25 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:25 +0000 UTC ContainersNotReady containers with unready status: [ruby mongodb]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:24 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: example-2-62lfw                                          ci-prtest-5a37c28-12465-ig-n-m4h4  Running    30s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:45 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:51 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:45 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: deployment-simple-1-xkksx                                ci-prtest-5a37c28-12465-ig-n-r9qb  Running    30s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:14 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:25 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:14 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: deployment-simple-2-deploy                               ci-prtest-5a37c28-12465-ig-n-r9qb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:27 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:28 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:27 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: deployment-simple-2-fqbxh                                ci-prtest-5a37c28-12465-ig-n-r9qb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:29 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:34 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:29 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: deployment-simple-1-f95pr                                ci-prtest-5a37c28-12465-ig-n-5rlb  Running    30s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:47 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:11 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:46 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: deployment-simple-1-qp5h9                                ci-prtest-5a37c28-12465-ig-n-m4h4  Running    30s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:46 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:15:02 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:46 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: deployment-simple-1-sbcnb                                ci-prtest-5a37c28-12465-ig-n-r9qb  Running    30s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:46 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:55 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:46 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: ruby-sample-build-td-2-build                             ci-prtest-5a37c28-12465-ig-n-5rlb  Running    30s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:28 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:30 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:13 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: multicast-0                                              ci-prtest-5a37c28-12465-ig-m-lq53  Failed            []
Dec  6 13:15:35.832: INFO: nodejsroot-1-build                                       ci-prtest-5a37c28-12465-ig-n-m4h4  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:48 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:49 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:14:45 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: nodejsroot-1-build                                       ci-prtest-5a37c28-12465-ig-n-5rlb  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:33 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:37 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:13:27 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: bootstrap-autoapprover-0                                 ci-prtest-5a37c28-12465-ig-m-lq53  Running           [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:11:50 +0000 UTC  } {Ready True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:12:30 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:11:50 +0000 UTC  }]
Dec  6 13:15:35.832: INFO: 
Dec  6 13:15:35.851: INFO: 
Logging node info for node ci-prtest-5a37c28-12465-ig-m-lq53
Dec  6 13:15:35.872: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:ci-prtest-5a37c28-12465-ig-m-lq53,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/ci-prtest-5a37c28-12465-ig-m-lq53,UID:ffa3ab2f-da86-11e7-ae30-42010a8e0005,ResourceVersion:10244,Generation:0,CreationTimestamp:2017-12-06 13:11:40 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: n1-standard-2,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: us-east1,failure-domain.beta.kubernetes.io/zone: us-east1-c,kubernetes.io/hostname: ci-prtest-5a37c28-12465-ig-m-lq53,role: infra,},Annotations:map[string]string{volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,},Spec:NodeSpec{PodCIDR:,ExternalID:1997431455840097769,ProviderID:gce://openshift-gce-devel-ci/us-east1-c/ci-prtest-5a37c28-12465-ig-m-lq53,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{cpu: {{2 0} {<nil>} 2 DecimalSI},memory: {{7674347520 0} {<nil>}  BinarySI},pods: {{20 0} {<nil>} 20 DecimalSI},},Allocatable:ResourceList{cpu: {{2 0} {<nil>} 2 DecimalSI},memory: {{7569489920 0} {<nil>}  BinarySI},pods: {{20 0} {<nil>} 20 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:11:40 +0000 UTC RouteCreated openshift-sdn cleared kubelet-set NoRouteCreated} {OutOfDisk False 2017-12-06 13:15:31 +0000 UTC 2017-12-06 13:11:40 +0000 UTC KubeletHasSufficientDisk kubelet has sufficient disk space available} {MemoryPressure False 2017-12-06 13:15:31 +0000 UTC 2017-12-06 13:11:40 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2017-12-06 13:15:31 +0000 UTC 2017-12-06 13:11:40 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {Ready True 2017-12-06 13:15:31 +0000 UTC 2017-12-06 13:11:50 +0000 UTC KubeletReady kubelet is posting ready status}],Addresses:[{InternalIP 10.142.0.5} {ExternalIP 35.196.105.253} {Hostname ci-prtest-5a37c28-12465-ig-m-lq53}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:9fb1a4c13ef4d5a05bca88646273b36f,SystemUUID:01A09519-CA32-263E-B0E9-706471968847,BootID:43f1c620-0dd3-42a9-aeb6-f3249371460a,KernelVersion:3.10.0-693.5.2.el7.x86_64,OSImage:Red Hat Enterprise Linux Server 7.4 (Maipo),ContainerRuntimeVersion:docker://1.12.6,KubeletVersion:v1.8.1+0d5291c,KubeProxyVersion:v1.8.1+0d5291c,OperatingSystem:linux,Architecture:amd64,},Images:[{[docker.io/openshift/origin-haproxy-router@sha256:9ea6f5724bb82ed8f1bd607af71bb8f154ded52827ff149a8ac1e92649549e2e docker.io/openshift/origin-haproxy-router:v3.9.0-alpha.0] 1304484210} {[docker.io/openshift/origin-deployer@sha256:ceb359db7040ec6c7ba9e94eb1fcc14198b259be972fe6c683e820d35130c8dc docker.io/openshift/origin-deployer:v3.9.0-alpha.0] 1282972459} {[docker.io/openshift/node@sha256:53f60230a465d731b8946c81af569c93e6d7b5187d58b907e5dbd7a71094c84c docker.io/openshift/node:v3.7.0-rc.0] 1279914095} {[docker.io/openshift/origin-docker-registry@sha256:78938d03c12b73ed92e4cd9a64c9177c9b8ef806afb5c7456e4358763556f975 docker.io/openshift/origin-docker-registry:v3.9.0-alpha.0] 480832662} {[docker.io/openshift/origin-pod@sha256:e1fb9c90b6f445e13c29d411c4926b370bc9e67a57ced9cbe6cf56598ff0d12d docker.io/openshift/origin-pod:v3.9.0-alpha.0] 224804012} {[gcr.io/kubernetes-e2e-test-images/hostexec-amd64@sha256:066848e78b757074c932cbafd33958685a9dc0627a5061cdf98a6143db055fbd gcr.io/kubernetes-e2e-test-images/hostexec-amd64:1.0] 8374783} {[gcr.io/kubernetes-e2e-test-images/netexec-amd64@sha256:2edfad424a541b9e024f26368d3a5b7dcc1d7cd27a4ee8c1d8c3f81d9209ab2e gcr.io/kubernetes-e2e-test-images/netexec-amd64:1.0] 6227659}],VolumesInUse:[],VolumesAttached:[],},}
Dec  6 13:15:35.872: INFO: 
Logging kubelet events for node ci-prtest-5a37c28-12465-ig-m-lq53
Dec  6 13:15:35.888: INFO: 
Logging pods the kubelet thinks is on node ci-prtest-5a37c28-12465-ig-m-lq53
Dec  6 13:15:35.943: INFO: docker-registry-1-vww25 started at 2017-12-06 13:12:49 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:35.943: INFO: 	Container registry ready: true, restart count 0
Dec  6 13:15:35.943: INFO: router-1-wcctt started at 2017-12-06 13:12:50 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:35.943: INFO: 	Container router ready: true, restart count 0
Dec  6 13:15:35.943: INFO: multicast-0 started at 2017-12-06 13:12:58 +0000 UTC (0+0 container statuses recorded)
Dec  6 13:15:35.943: INFO: bootstrap-autoapprover-0 started at 2017-12-06 13:11:50 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:35.943: INFO: 	Container signer ready: true, restart count 0
W1206 13:15:35.964529   18115 metrics_grabber.go:81] Master node is not registered. Grabbing metrics from Scheduler, ControllerManager and ClusterAutoscaler is disabled.
Dec  6 13:15:36.052: INFO: 
Latency metrics for node ci-prtest-5a37c28-12465-ig-m-lq53
Dec  6 13:15:36.052: INFO: {Operation: Method:pod_start_latency_microseconds Quantile:0.99 Latency:35.998332s}
Dec  6 13:15:36.052: INFO: {Operation:pull_image Method:docker_operations_latency_microseconds Quantile:0.99 Latency:19.799914s}
Dec  6 13:15:36.052: INFO: {Operation:pull_image Method:docker_operations_latency_microseconds Quantile:0.9 Latency:19.799914s}
Dec  6 13:15:36.052: INFO: 
Logging node info for node ci-prtest-5a37c28-12465-ig-n-5rlb
Dec  6 13:15:36.071: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:ci-prtest-5a37c28-12465-ig-n-5rlb,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/ci-prtest-5a37c28-12465-ig-n-5rlb,UID:ffecb235-da86-11e7-ae30-42010a8e0005,ResourceVersion:10217,Generation:0,CreationTimestamp:2017-12-06 13:11:41 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: n1-standard-2,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: us-east1,failure-domain.beta.kubernetes.io/zone: us-east1-c,kubernetes.io/hostname: ci-prtest-5a37c28-12465-ig-n-5rlb,role: app,},Annotations:map[string]string{volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,},Spec:NodeSpec{PodCIDR:,ExternalID:2005186354300474857,ProviderID:gce://openshift-gce-devel-ci/us-east1-c/ci-prtest-5a37c28-12465-ig-n-5rlb,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{cpu: {{2 0} {<nil>} 2 DecimalSI},memory: {{7674347520 0} {<nil>}  BinarySI},pods: {{40 0} {<nil>} 40 DecimalSI},},Allocatable:ResourceList{cpu: {{2 0} {<nil>} 2 DecimalSI},memory: {{7569489920 0} {<nil>}  BinarySI},pods: {{40 0} {<nil>} 40 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:11:41 +0000 UTC RouteCreated openshift-sdn cleared kubelet-set NoRouteCreated} {OutOfDisk False 2017-12-06 13:15:31 +0000 UTC 2017-12-06 13:11:41 +0000 UTC KubeletHasSufficientDisk kubelet has sufficient disk space available} {MemoryPressure False 2017-12-06 13:15:31 +0000 UTC 2017-12-06 13:11:41 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2017-12-06 13:15:31 +0000 UTC 2017-12-06 13:11:41 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {Ready True 2017-12-06 13:15:31 +0000 UTC 2017-12-06 13:11:51 +0000 UTC KubeletReady kubelet is posting ready status}],Addresses:[{InternalIP 10.142.0.4} {ExternalIP 35.185.105.83} {Hostname ci-prtest-5a37c28-12465-ig-n-5rlb}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:9fb1a4c13ef4d5a05bca88646273b36f,SystemUUID:FBD15D5B-CEB3-592C-6496-A3314EDCEF8B,BootID:9a306677-6d55-4a2a-981b-ddc42bae018f,KernelVersion:3.10.0-693.5.2.el7.x86_64,OSImage:Red Hat Enterprise Linux Server 7.4 (Maipo),ContainerRuntimeVersion:docker://1.12.6,KubeletVersion:v1.8.1+0d5291c,KubeProxyVersion:v1.8.1+0d5291c,OperatingSystem:linux,Architecture:amd64,},Images:[{[docker.io/openshift/origin-sti-builder@sha256:cf48dc81aee5649bff2c2f58e1cf71d76bd6d7219dd5218b612a76fd93dab015 docker.io/openshift/origin-sti-builder:v3.9.0-alpha.0] 1282972459} {[docker.io/openshift/origin-docker-builder@sha256:a69d625874a9e528ee77887451b22ca565364da469fc4f0c5002e2a37162c2ee docker.io/openshift/origin-docker-builder:v3.9.0-alpha.0] 1282972459} {[docker.io/openshift/origin-deployer@sha256:ceb359db7040ec6c7ba9e94eb1fcc14198b259be972fe6c683e820d35130c8dc docker.io/openshift/origin-deployer:v3.9.0-alpha.0] 1282972459} {[docker-registry.default.svc:5000/extended-test-build-valuefrom-cxkdg-h9vh6/test:latest] 596859476} {[<none>@<none> <none>:<none>] 527067612} {[docker.io/centos/ruby-24-centos7@sha256:ccd5f84fc4aa6ea7501286f307e5fe3f77c70369f44b2138a02dc56fb2f74017] 527056322} {[docker.io/centos/nodejs-6-centos7@sha256:0a2cb65310bc8b40ce62c288427671211caa126091d80f59a9ba04c9caaae134] 512180683} {[docker-registry.default.svc:5000/extended-test-s2i-build-root-qsrp8-vcv4n/nodejsroot:latest] 512180683} {[docker.io/centos/s2i-base-centos7@sha256:0baeca9d812cc64fb3ed6be79a624401a0263934ba8eda18c97f7d44a027aee6 docker.io/centos/s2i-base-centos7:latest] 480459650} {[docker.io/openshift/origin-base@sha256:d97d3e7e043bf8a6edcbbe31e00a656f902ae88647129928b5e8dffcbc0d1e94 docker.io/openshift/origin-base:latest] 394924906} {[docker.io/openshift/origin-pod@sha256:e1fb9c90b6f445e13c29d411c4926b370bc9e67a57ced9cbe6cf56598ff0d12d docker.io/openshift/origin-pod:v3.9.0-alpha.0] 224804012} {[docker-registry.default.svc:5000/extended-test-docker-build-pullsecret-v75bh-s7vvh/image1@sha256:b1a6bc41a5b01ab68d1b81c87483e33e4735e7bd73b45c1ad8ede9e720cb4516 docker-registry.default.svc:5000/extended-test-docker-build-pullsecret-v75bh-s7vvh/image1:latest] 203545788} {[docker.io/centos@sha256:3b1a65e9a05f0a77b5e8a698d3359459904c2a354dc3b25ae2e2f5c95f0b3667 docker.io/centos:7 docker.io/centos:centos7] 203545788} {[gcr.io/google-containers/nginx-slim-amd64@sha256:6654db6d4028756062edac466454ee5c9cf9b20ef79e35a81e3c840031eb1e2b gcr.io/google-containers/nginx-slim-amd64:0.20] 103591055} {[gcr.io/kubernetes-e2e-test-images/netexec-amd64@sha256:2edfad424a541b9e024f26368d3a5b7dcc1d7cd27a4ee8c1d8c3f81d9209ab2e gcr.io/kubernetes-e2e-test-images/netexec-amd64:1.0] 6227659} {[gcr.io/kubernetes-e2e-test-images/porter-amd64@sha256:b5923cab026ae1a96325823e10254c9beda240126355a20ca64b59445ec631bb gcr.io/kubernetes-e2e-test-images/porter-amd64:1.0] 4400998} {[gcr.io/kubernetes-e2e-test-images/entrypoint-tester-amd64@sha256:ed08ffff86b0a2016fa650ff76ea4b85fc3dfcab30ee4b7bd47d514ab765da89 gcr.io/kubernetes-e2e-test-images/entrypoint-tester-amd64:1.0] 2276578} {[gcr.io/kubernetes-e2e-test-images/mounttest-user-amd64@sha256:dda6519a95c934b46731a6b1492fed1b48ccc6d4aed4b754a46d7de8063a3e2b gcr.io/kubernetes-e2e-test-images/mounttest-user-amd64:1.0] 1450451} {[gcr.io/kubernetes-e2e-test-images/mounttest-amd64@sha256:dc4e2dcfbde16249c4662de673295d00778577bc2e2ca7013a1b85d4f47398ca gcr.io/kubernetes-e2e-test-images/mounttest-amd64:1.0] 1450451} {[docker.io/busybox@sha256:bbc3a03235220b170ba48a157dd097dd1379299370e1ed99ce976df0355d24f0 docker.io/busybox:latest] 1129289}],VolumesInUse:[],VolumesAttached:[],},}
Dec  6 13:15:36.071: INFO: 
Logging kubelet events for node ci-prtest-5a37c28-12465-ig-n-5rlb
Dec  6 13:15:36.087: INFO: 
Logging pods the kubelet thinks is on node ci-prtest-5a37c28-12465-ig-n-5rlb
Dec  6 13:15:36.208: INFO: deployment-simple-1-f95pr started at 2017-12-06 13:14:47 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Container myapp ready: true, restart count 0
Dec  6 13:15:36.208: INFO: nodejsroot-1-build started at 2017-12-06 13:13:27 +0000 UTC (1+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Init container manage-dockerfile ready: true, restart count 0
Dec  6 13:15:36.208: INFO: 	Container docker-build ready: true, restart count 0
Dec  6 13:15:36.208: INFO: mydockertest-1-build started at 2017-12-06 13:13:02 +0000 UTC (2+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Init container git-clone ready: true, restart count 0
Dec  6 13:15:36.208: INFO: 	Init container manage-dockerfile ready: true, restart count 0
Dec  6 13:15:36.208: INFO: 	Container docker-build ready: true, restart count 0
Dec  6 13:15:36.208: INFO: annotationupdate778b4425-da87-11e7-bb0b-0e9fdaedd9a2 started at 2017-12-06 13:15:01 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Container client-container ready: false, restart count 0
Dec  6 13:15:36.208: INFO: test-webserver-896c3786-da87-11e7-a5ed-0e9fdaedd9a2 started at 2017-12-06 13:15:32 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Container test-webserver ready: false, restart count 0
Dec  6 13:15:36.208: INFO: isolation-webserver started at 2017-12-06 13:15:00 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Container isolation-webserver-container ready: true, restart count 0
Dec  6 13:15:36.208: INFO: service-scrck started at 2017-12-06 13:14:13 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Container service-scrck-container ready: false, restart count 0
Dec  6 13:15:36.208: INFO: history-limit-6-deploy started at 2017-12-06 13:14:52 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Container deployment ready: true, restart count 0
Dec  6 13:15:36.208: INFO: execpod-sourceip-ci-prtest-5a37c28-12465-ig-n-5rlbg6hpk started at <nil> (0+0 container statuses recorded)
Dec  6 13:15:36.208: INFO: history-limit-2-jncx5 started at 2017-12-06 13:13:59 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Container myapp ready: false, restart count 0
Dec  6 13:15:36.208: INFO: ruby-sample-build-td-2-build started at 2017-12-06 13:14:13 +0000 UTC (2+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Init container git-clone ready: true, restart count 0
Dec  6 13:15:36.208: INFO: 	Init container manage-dockerfile ready: true, restart count 0
Dec  6 13:15:36.208: INFO: 	Container docker-build ready: true, restart count 0
Dec  6 13:15:36.208: INFO: history-limit-6-695mh started at 2017-12-06 13:15:01 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.208: INFO: 	Container myapp ready: false, restart count 0
W1206 13:15:36.226409   18115 metrics_grabber.go:81] Master node is not registered. Grabbing metrics from Scheduler, ControllerManager and ClusterAutoscaler is disabled.
Dec  6 13:15:36.317: INFO: 
Latency metrics for node ci-prtest-5a37c28-12465-ig-n-5rlb
Dec  6 13:15:36.317: INFO: {Operation: Method:pod_start_latency_microseconds Quantile:0.99 Latency:34.856354s}
Dec  6 13:15:36.317: INFO: {Operation:stop_container Method:docker_operations_latency_microseconds Quantile:0.99 Latency:30.916829s}
Dec  6 13:15:36.317: INFO: {Operation:create Method:pod_worker_latency_microseconds Quantile:0.9 Latency:24.332889s}
Dec  6 13:15:36.317: INFO: {Operation:create Method:pod_worker_latency_microseconds Quantile:0.99 Latency:24.332889s}
Dec  6 13:15:36.317: INFO: {Operation:pull_image Method:docker_operations_latency_microseconds Quantile:0.99 Latency:21.966385s}
Dec  6 13:15:36.317: INFO: {Operation:pull_image Method:docker_operations_latency_microseconds Quantile:0.9 Latency:16.879207s}
Dec  6 13:15:36.317: INFO: {Operation: Method:pod_start_latency_microseconds Quantile:0.9 Latency:14.40585s}
Dec  6 13:15:36.317: INFO: {Operation:create Method:pod_worker_latency_microseconds Quantile:0.5 Latency:13.39532s}
Dec  6 13:15:36.317: INFO: 
Logging node info for node ci-prtest-5a37c28-12465-ig-n-m4h4
Dec  6 13:15:36.335: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:ci-prtest-5a37c28-12465-ig-n-m4h4,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/ci-prtest-5a37c28-12465-ig-n-m4h4,UID:fdcaee2e-da86-11e7-ae30-42010a8e0005,ResourceVersion:10398,Generation:0,CreationTimestamp:2017-12-06 13:11:37 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: n1-standard-2,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: us-east1,failure-domain.beta.kubernetes.io/zone: us-east1-c,kubernetes.io/hostname: ci-prtest-5a37c28-12465-ig-n-m4h4,role: app,},Annotations:map[string]string{volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,},Spec:NodeSpec{PodCIDR:,ExternalID:7967258211403847145,ProviderID:gce://openshift-gce-devel-ci/us-east1-c/ci-prtest-5a37c28-12465-ig-n-m4h4,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{cpu: {{2 0} {<nil>} 2 DecimalSI},memory: {{7674347520 0} {<nil>}  BinarySI},pods: {{40 0} {<nil>} 40 DecimalSI},},Allocatable:ResourceList{cpu: {{2 0} {<nil>} 2 DecimalSI},memory: {{7569489920 0} {<nil>}  BinarySI},pods: {{40 0} {<nil>} 40 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:11:37 +0000 UTC RouteCreated openshift-sdn cleared kubelet-set NoRouteCreated} {OutOfDisk False 2017-12-06 13:15:34 +0000 UTC 2017-12-06 13:11:37 +0000 UTC KubeletHasSufficientDisk kubelet has sufficient disk space available} {MemoryPressure False 2017-12-06 13:15:34 +0000 UTC 2017-12-06 13:11:37 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2017-12-06 13:15:34 +0000 UTC 2017-12-06 13:11:37 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {Ready True 2017-12-06 13:15:34 +0000 UTC 2017-12-06 13:11:47 +0000 UTC KubeletReady kubelet is posting ready status}],Addresses:[{InternalIP 10.142.0.2} {ExternalIP 104.196.24.61} {Hostname ci-prtest-5a37c28-12465-ig-n-m4h4}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:9fb1a4c13ef4d5a05bca88646273b36f,SystemUUID:D10E8AFD-B7A4-AE54-3FD1-C3DE26609DE6,BootID:1a732b9c-58e4-4baf-b66e-422da4d9937d,KernelVersion:3.10.0-693.5.2.el7.x86_64,OSImage:Red Hat Enterprise Linux Server 7.4 (Maipo),ContainerRuntimeVersion:docker://1.12.6,KubeletVersion:v1.8.1+0d5291c,KubeProxyVersion:v1.8.1+0d5291c,OperatingSystem:linux,Architecture:amd64,},Images:[{[docker.io/openshift/origin-docker-builder@sha256:a69d625874a9e528ee77887451b22ca565364da469fc4f0c5002e2a37162c2ee docker.io/openshift/origin-docker-builder:v3.9.0-alpha.0] 1282972459} {[docker.io/openshift/origin-sti-builder@sha256:cf48dc81aee5649bff2c2f58e1cf71d76bd6d7219dd5218b612a76fd93dab015 docker.io/openshift/origin-sti-builder:v3.9.0-alpha.0] 1282972459} {[docker.io/openshift/origin-deployer@sha256:ceb359db7040ec6c7ba9e94eb1fcc14198b259be972fe6c683e820d35130c8dc docker.io/openshift/origin-deployer:v3.9.0-alpha.0] 1282972459} {[docker.io/centos/ruby-22-centos7@sha256:9b8b3eae7f5346d7d6b8269424d1149fcf0f0b98f2d617a187c36c5b3b05f7ba docker.io/centos/ruby-22-centos7:latest] 546065783} {[<none>@<none> <none>:<none>] 527067612} {[docker.io/centos/ruby-24-centos7@sha256:ccd5f84fc4aa6ea7501286f307e5fe3f77c70369f44b2138a02dc56fb2f74017] 527056322} {[docker.io/centos/nodejs-6-centos7@sha256:0a2cb65310bc8b40ce62c288427671211caa126091d80f59a9ba04c9caaae134] 512180683} {[docker-registry.default.svc:5000/extended-test-s2i-build-root-9vzmg-mphrx/nodejsroot:latest] 512180683} {[docker.io/openshift/origin-pod@sha256:e1fb9c90b6f445e13c29d411c4926b370bc9e67a57ced9cbe6cf56598ff0d12d docker.io/openshift/origin-pod:v3.9.0-alpha.0] 224804012} {[docker-registry.default.svc:5000/extended-test-docker-build-pullsecret-v75bh-s7vvh/image1@sha256:b1a6bc41a5b01ab68d1b81c87483e33e4735e7bd73b45c1ad8ede9e720cb4516] 203545788} {[docker.io/centos@sha256:3b1a65e9a05f0a77b5e8a698d3359459904c2a354dc3b25ae2e2f5c95f0b3667 docker.io/centos:centos7] 203545788} {[gcr.io/google-containers/nginx-slim-amd64@sha256:6654db6d4028756062edac466454ee5c9cf9b20ef79e35a81e3c840031eb1e2b gcr.io/google-containers/nginx-slim-amd64:0.20] 103591055} {[gcr.io/kubernetes-e2e-test-images/nettest-amd64@sha256:ff598458029b42e23b823a3a690c07e1f6921627f3fc49d007033494eca13141 gcr.io/kubernetes-e2e-test-images/nettest-amd64:1.0] 30381916} {[gcr.io/kubernetes-e2e-test-images/netexec-amd64@sha256:2edfad424a541b9e024f26368d3a5b7dcc1d7cd27a4ee8c1d8c3f81d9209ab2e gcr.io/kubernetes-e2e-test-images/netexec-amd64:1.0] 6227659} {[gcr.io/kubernetes-e2e-test-images/serve-hostname-amd64@sha256:2dd4032e98a0450d95a0ac71a5e465f542a900812d8c41bc6ca635aed1a5fc91 gcr.io/kubernetes-e2e-test-images/serve-hostname-amd64:1.0] 5470001} {[gcr.io/kubernetes-e2e-test-images/mounttest-user-amd64@sha256:dda6519a95c934b46731a6b1492fed1b48ccc6d4aed4b754a46d7de8063a3e2b gcr.io/kubernetes-e2e-test-images/mounttest-user-amd64:1.0] 1450451} {[gcr.io/kubernetes-e2e-test-images/mounttest-amd64@sha256:dc4e2dcfbde16249c4662de673295d00778577bc2e2ca7013a1b85d4f47398ca gcr.io/kubernetes-e2e-test-images/mounttest-amd64:1.0] 1450451} {[docker.io/busybox@sha256:bbc3a03235220b170ba48a157dd097dd1379299370e1ed99ce976df0355d24f0 docker.io/busybox:latest] 1129289} {[docker.io/busybox@sha256:29f5d56d12684887bdfa50dcd29fc31eea4aaf4ad3bec43daf19026a7ce69912] 1093484} {[gcr.io/google_containers/pause-amd64@sha256:163ac025575b775d1c0f9bf0bdd0f086883171eb475b5068e7defa4ca9e76516 gcr.io/google_containers/pause-amd64:3.0] 746888}],VolumesInUse:[],VolumesAttached:[],},}
Dec  6 13:15:36.335: INFO: 
Logging kubelet events for node ci-prtest-5a37c28-12465-ig-n-m4h4
Dec  6 13:15:36.350: INFO: 
Logging pods the kubelet thinks is on node ci-prtest-5a37c28-12465-ig-n-m4h4
Dec  6 13:15:36.388: INFO: custom-deployment-1-qj7q9 started at 2017-12-06 13:15:07 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.388: INFO: 	Container myapp ready: true, restart count 1
Dec  6 13:15:36.388: INFO: liveness-exec started at 2017-12-06 13:13:13 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.388: INFO: 	Container liveness ready: true, restart count 0
Dec  6 13:15:36.388: INFO: example-2-62lfw started at 2017-12-06 13:14:45 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.388: INFO: 	Container test ready: true, restart count 0
Dec  6 13:15:36.388: INFO: pod-init-735d02e3-da87-11e7-9c89-0e9fdaedd9a2 started at 2017-12-06 13:14:54 +0000 UTC (2+1 container statuses recorded)
Dec  6 13:15:36.388: INFO: 	Init container init1 ready: true, restart count 0
Dec  6 13:15:36.388: INFO: 	Init container init2 ready: true, restart count 0
Dec  6 13:15:36.388: INFO: 	Container run1 ready: false, restart count 0
Dec  6 13:15:36.388: INFO: deployment-simple-1-qp5h9 started at 2017-12-06 13:14:46 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.388: INFO: 	Container myapp ready: true, restart count 0
Dec  6 13:15:36.388: INFO: myphp-2-build started at 2017-12-06 13:14:35 +0000 UTC (2+1 container statuses recorded)
Dec  6 13:15:36.388: INFO: 	Init container git-clone ready: true, restart count 0
Dec  6 13:15:36.388: INFO: 	Init container manage-dockerfile ready: true, restart count 0
Dec  6 13:15:36.388: INFO: 	Container sti-build ready: false, restart count 0
Dec  6 13:15:36.388: INFO: example-1-t9qwv started at 2017-12-06 13:15:25 +0000 UTC (0+2 container statuses recorded)
Dec  6 13:15:36.388: INFO: 	Container mongodb ready: false, restart count 0
Dec  6 13:15:36.388: INFO: 	Container ruby ready: false, restart count 0
Dec  6 13:15:36.388: INFO: nodejsroot-1-build started at 2017-12-06 13:14:45 +0000 UTC (1+1 container statuses recorded)
Dec  6 13:15:36.388: INFO: 	Init container manage-dockerfile ready: true, restart count 0
Dec  6 13:15:36.388: INFO: 	Container docker-build ready: true, restart count 0
W1206 13:15:36.405125   18115 metrics_grabber.go:81] Master node is not registered. Grabbing metrics from Scheduler, ControllerManager and ClusterAutoscaler is disabled.
Dec  6 13:15:36.506: INFO: 
Latency metrics for node ci-prtest-5a37c28-12465-ig-n-m4h4
Dec  6 13:15:36.506: INFO: {Operation: Method:pod_start_latency_microseconds Quantile:0.99 Latency:24.642119s}
Dec  6 13:15:36.506: INFO: {Operation: Method:pod_start_latency_microseconds Quantile:0.9 Latency:10.005255s}
Dec  6 13:15:36.506: INFO: 
Logging node info for node ci-prtest-5a37c28-12465-ig-n-r9qb
Dec  6 13:15:36.535: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:ci-prtest-5a37c28-12465-ig-n-r9qb,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/ci-prtest-5a37c28-12465-ig-n-r9qb,UID:fd9dac46-da86-11e7-ae30-42010a8e0005,ResourceVersion:10157,Generation:0,CreationTimestamp:2017-12-06 13:11:37 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: n1-standard-2,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: us-east1,failure-domain.beta.kubernetes.io/zone: us-east1-c,kubernetes.io/hostname: ci-prtest-5a37c28-12465-ig-n-r9qb,role: app,},Annotations:map[string]string{volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,},Spec:NodeSpec{PodCIDR:,ExternalID:7914987862411073001,ProviderID:gce://openshift-gce-devel-ci/us-east1-c/ci-prtest-5a37c28-12465-ig-n-r9qb,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{cpu: {{2 0} {<nil>} 2 DecimalSI},memory: {{7674347520 0} {<nil>}  BinarySI},pods: {{40 0} {<nil>} 40 DecimalSI},},Allocatable:ResourceList{cpu: {{2 0} {<nil>} 2 DecimalSI},memory: {{7569489920 0} {<nil>}  BinarySI},pods: {{40 0} {<nil>} 40 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 0001-01-01 00:00:00 +0000 UTC 2017-12-06 13:11:37 +0000 UTC RouteCreated openshift-sdn cleared kubelet-set NoRouteCreated} {OutOfDisk False 2017-12-06 13:15:28 +0000 UTC 2017-12-06 13:11:37 +0000 UTC KubeletHasSufficientDisk kubelet has sufficient disk space available} {MemoryPressure False 2017-12-06 13:15:28 +0000 UTC 2017-12-06 13:11:37 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2017-12-06 13:15:28 +0000 UTC 2017-12-06 13:11:37 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {Ready True 2017-12-06 13:15:28 +0000 UTC 2017-12-06 13:11:47 +0000 UTC KubeletReady kubelet is posting ready status}],Addresses:[{InternalIP 10.142.0.3} {ExternalIP 35.185.96.205} {Hostname ci-prtest-5a37c28-12465-ig-n-r9qb}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:9fb1a4c13ef4d5a05bca88646273b36f,SystemUUID:5E2059B8-DF9B-3B24-9003-92EC7E9DF632,BootID:793fb4fa-9b90-4729-8f5a-ac5c42277155,KernelVersion:3.10.0-693.5.2.el7.x86_64,OSImage:Red Hat Enterprise Linux Server 7.4 (Maipo),ContainerRuntimeVersion:docker://1.12.6,KubeletVersion:v1.8.1+0d5291c,KubeProxyVersion:v1.8.1+0d5291c,OperatingSystem:linux,Architecture:amd64,},Images:[{[docker.io/openshift/origin-sti-builder@sha256:cf48dc81aee5649bff2c2f58e1cf71d76bd6d7219dd5218b612a76fd93dab015 docker.io/openshift/origin-sti-builder:v3.9.0-alpha.0] 1282972459} {[docker.io/openshift/origin-deployer@sha256:ceb359db7040ec6c7ba9e94eb1fcc14198b259be972fe6c683e820d35130c8dc docker.io/openshift/origin-deployer:v3.9.0-alpha.0] 1282972459} {[docker.io/centos/php-70-centos7@sha256:8cc40311fd5403aece4374e20ddb107c1cd9361564ec999d929b6b4714235ef4] 589081324} {[docker.io/centos/ruby-24-centos7@sha256:ccd5f84fc4aa6ea7501286f307e5fe3f77c70369f44b2138a02dc56fb2f74017] 527056322} {[docker.io/cockpit/kubernetes@sha256:0745b3823efc57e03a5ef378614dfcb6c2b1e3964220bbf908fb3046a91cef70 docker.io/cockpit/kubernetes:latest] 350062743} {[docker.io/openshift/origin-pod@sha256:e1fb9c90b6f445e13c29d411c4926b370bc9e67a57ced9cbe6cf56598ff0d12d docker.io/openshift/origin-pod:v3.9.0-alpha.0] 224804012} {[docker.io/centos@sha256:3b1a65e9a05f0a77b5e8a698d3359459904c2a354dc3b25ae2e2f5c95f0b3667 docker.io/centos:centos7] 203545788} {[gcr.io/kubernetes-e2e-test-images/netexec-amd64@sha256:2edfad424a541b9e024f26368d3a5b7dcc1d7cd27a4ee8c1d8c3f81d9209ab2e gcr.io/kubernetes-e2e-test-images/netexec-amd64:1.0] 6227659} {[gcr.io/kubernetes-e2e-test-images/mounttest-user-amd64@sha256:dda6519a95c934b46731a6b1492fed1b48ccc6d4aed4b754a46d7de8063a3e2b gcr.io/kubernetes-e2e-test-images/mounttest-user-amd64:1.0] 1450451} {[gcr.io/kubernetes-e2e-test-images/mounttest-amd64@sha256:dc4e2dcfbde16249c4662de673295d00778577bc2e2ca7013a1b85d4f47398ca gcr.io/kubernetes-e2e-test-images/mounttest-amd64:1.0] 1450451} {[docker.io/busybox@sha256:91ef6c1c52b166be02645b8efee30d1ee65362024f7da41c404681561734c465 docker.io/busybox@sha256:bbc3a03235220b170ba48a157dd097dd1379299370e1ed99ce976df0355d24f0 docker.io/busybox:latest] 1129289} {[gcr.io/google_containers/pause-amd64@sha256:163ac025575b775d1c0f9bf0bdd0f086883171eb475b5068e7defa4ca9e76516 gcr.io/google_containers/pause-amd64:3.0] 746888}],VolumesInUse:[],VolumesAttached:[],},}
Dec  6 13:15:36.535: INFO: 
Logging kubelet events for node ci-prtest-5a37c28-12465-ig-n-r9qb
Dec  6 13:15:36.553: INFO: 
Logging pods the kubelet thinks is on node ci-prtest-5a37c28-12465-ig-n-r9qb
Dec  6 13:15:36.596: INFO: history-limit-5-tssv5 started at 2017-12-06 13:14:46 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.597: INFO: 	Container myapp ready: true, restart count 0
Dec  6 13:15:36.597: INFO: registry-console-1-vjcxx started at 2017-12-06 13:12:52 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.597: INFO: 	Container registry-console ready: true, restart count 0
Dec  6 13:15:36.597: INFO: myphp-1-build started at 2017-12-06 13:13:34 +0000 UTC (2+1 container statuses recorded)
Dec  6 13:15:36.597: INFO: 	Init container git-clone ready: true, restart count 0
Dec  6 13:15:36.597: INFO: 	Init container manage-dockerfile ready: true, restart count 0
Dec  6 13:15:36.597: INFO: 	Container sti-build ready: false, restart count 0
Dec  6 13:15:36.597: INFO: example-1-deploy started at 2017-12-06 13:15:23 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.597: INFO: 	Container deployment ready: true, restart count 0
Dec  6 13:15:36.597: INFO: custom-deployment-1-r9wpm started at 2017-12-06 13:15:07 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.597: INFO: 	Container myapp ready: false, restart count 1
Dec  6 13:15:36.597: INFO: deployment-simple-1-xkksx started at 2017-12-06 13:15:14 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.597: INFO: 	Container myapp ready: true, restart count 0
Dec  6 13:15:36.597: INFO: deployment-simple-2-fqbxh started at 2017-12-06 13:15:29 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.597: INFO: 	Container myapp ready: true, restart count 0
Dec  6 13:15:36.597: INFO: deployment-simple-1-sbcnb started at 2017-12-06 13:14:46 +0000 UTC (0+1 container statuses recorded)
Dec  6 13:15:36.597: INFO: 	Container myapp ready: true, restart count 0
W1206 13:15:36.635116   18115 metrics_grabber.go:81] Master node is not registered. Grabbing metrics from Scheduler, ControllerManager and ClusterAutoscaler is disabled.
Dec  6 13:15:36.760: INFO: 
Latency metrics for node ci-prtest-5a37c28-12465-ig-n-r9qb
Dec  6 13:15:36.760: INFO: {Operation: Method:pod_start_latency_microseconds Quantile:0.99 Latency:30.452208s}
Dec  6 13:15:36.760: INFO: {Operation:stop_container Method:docker_operations_latency_microseconds Quantile:0.99 Latency:30.048693s}
Dec  6 13:15:36.760: INFO: {Operation:pull_image Method:docker_operations_latency_microseconds Quantile:0.99 Latency:21.726083s}
Dec  6 13:15:36.760: INFO: {Operation:pull_image Method:docker_operations_latency_microseconds Quantile:0.9 Latency:16.800988s}
STEP: Dumping a list of prepulled images on each node...
Dec  6 13:15:36.797: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "extended-test-cli-deployment-h94tt-x597n" for this suite.
Dec  6 13:15:45.917: INFO: namespace: extended-test-cli-deployment-h94tt-x597n, resource: bindings, ignored listing per whitelist
Dec  6 13:15:46.326: INFO: namespace extended-test-cli-deployment-h94tt-x597n deletion completed in 9.483252479s


• Failure [46.983 seconds]
[Feature:DeploymentConfig] deploymentconfigs
/go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:1380
  with custom deployments [Conformance]
  /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:564
    should run the custom deployment steps [Suite:openshift/conformance/parallel] [It]
    /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:563

    Expected
        <string>: Command "deploy" is deprecated, Use the `rollout latest` and `rollout cancel` commands instead.
    to contain substring
        <string>: --> pre: Running hook pod ...

    /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/test/extended/deployments/deployments.go:553

The text was updated successfully, but these errors were encountered:

php-coder · 2017-12-06T15:11:26Z

CC @tnozicka

mfojtik · 2017-12-06T16:38:15Z

seen here as well https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/17628/test_pull_request_origin_extended_conformance_gce/12469/

/assign tnozicka

tnozicka · 2017-12-11T16:05:43Z

@mfojtik I think those are 2 different flakes

in the first case this is either journald (@soltysh ?) or docker logs issue because the deployer pod completed succesfully

ec  6 13:15:35.770: INFO: At 2017-12-06 13:15:19 +0000 UTC - event for custom-deployment: {custom-deployment-1-deploy } Started: Running pre-hook ("/bin/echo test pre hook executed") for rc extended-test-cli-deployment-h94tt-x597n/custom-deployment-1
Dec  6 13:15:35.770: INFO: At 2017-12-06 13:15:19 +0000 UTC - event for custom-deployment: {custom-deployment-1-deploy } Completed: The pre-hook for rc extended-test-cli-deployment-h94tt-x597n/custom-deployment-1 completed successfully

in the second case it got stuck on failed (regular) pods:

Dec  6 14:53:14.339: INFO: At 2017-12-06 14:38:34 +0000 UTC - event for custom-deployment-1-h8rpp: {kubelet ci-prtest-5a37c28-12469-ig-n-hvz3} BackOff: Back-off restarting failed container
Dec  6 14:53:14.339: INFO: At 2017-12-06 14:39:21 +0000 UTC - event for custom-deployment-1-ztd6v: {kubelet ci-prtest-5a37c28-12469-ig-n-scf5} BackOff: Back-off restarting failed container

not really sure how /bin/bash sleep 10 could fail with Back-off restarting failed container so this is likely something wrong on a pod/infra level

soltysh · 2017-12-12T17:33:13Z

Journals can be easily checked, look for 'Suppressed x messages from....', if it doesn't exist it's not journald. If it does ping me.

…

On Dec 11, 2017 5:06 PM, "Tomáš Nožička" ***@***.***> wrote: @mfojtik <https://github.com/mfojtik> I think those are 2 different flakes in the first case this is either journald ***@***.*** <https://github.com/soltysh> ?) or docker logs issue because the deployer pod completed succesfully ec 6 13:15:35.770: INFO: At 2017-12-06 13:15:19 +0000 UTC - event for custom-deployment: {custom-deployment-1-deploy } Started: Running pre-hook ("/bin/echo test pre hook executed") for rc extended-test-cli-deployment-h94tt-x597n/custom-deployment-1 Dec 6 13:15:35.770: INFO: At 2017-12-06 13:15:19 +0000 UTC - event for custom-deployment: {custom-deployment-1-deploy } Completed: The pre-hook for rc extended-test-cli-deployment-h94tt-x597n/custom-deployment-1 completed successfully in the second case it got stuck on failed (regular) pods: Dec 6 14:53:14.339: INFO: At 2017-12-06 14:38:34 +0000 UTC - event for custom-deployment-1-h8rpp: {kubelet ci-prtest-5a37c28-12469-ig-n-hvz3} BackOff: Back-off restarting failed container Dec 6 14:53:14.339: INFO: At 2017-12-06 14:39:21 +0000 UTC - event for custom-deployment-1-ztd6v: {kubelet ci-prtest-5a37c28-12469-ig-n-scf5} BackOff: Back-off restarting failed container not really sure how /bin/bash sleep 10 could fail with Back-off restarting failed container so this is likely something wrong on a pod/infra level — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#17631 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAjLVQuwI4aFbIwXmRx77o1pH_zUPv1cks5s_VLmgaJpZM4Q4D97> .

tnozicka · 2017-12-13T16:07:26Z

closing in favor of #17747

php-coder added the kind/test-flake Categorizes issue or PR as related to test flakes. label Dec 6, 2017

php-coder mentioned this issue Dec 6, 2017

Fail fast when request to /.well-known/oauth-authorization-server fails #17606

Merged

openshift-ci-robot assigned tnozicka Dec 6, 2017

pweil- added component/apps priority/P1 labels Dec 7, 2017

tnozicka mentioned this issue Dec 11, 2017

[WIP] - Cleanup custom deployments test #17713

Closed

tnozicka mentioned this issue Dec 13, 2017

container logs lose line(s) (the last one) #17747

Closed

tnozicka closed this as completed Dec 13, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Conformance] deploymentconfigs with custom deployments should run the custom deployment steps flakes #17631

[Conformance] deploymentconfigs with custom deployments should run the custom deployment steps flakes #17631

php-coder commented Dec 6, 2017

php-coder commented Dec 6, 2017

mfojtik commented Dec 6, 2017

tnozicka commented Dec 11, 2017

soltysh commented Dec 12, 2017 via email

tnozicka commented Dec 13, 2017

[Conformance] deploymentconfigs with custom deployments should run the custom deployment steps flakes #17631

[Conformance] deploymentconfigs with custom deployments should run the custom deployment steps flakes #17631

Comments

php-coder commented Dec 6, 2017

php-coder commented Dec 6, 2017

mfojtik commented Dec 6, 2017

tnozicka commented Dec 11, 2017

soltysh commented Dec 12, 2017 via email

tnozicka commented Dec 13, 2017