SuccessConsole Output

Skipping 3,658 KB.. Full Log
    		I0615 18:36:16.941898   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.291378ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:16.966303   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.59851ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:16.966522   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.392439ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:16.966687   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (4.510831ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:16.966869   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (3.636108ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:16.967017   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (4.250771ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:16.973548   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.764812ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.155625   32116 wrap.go:42] GET /api/v1/persistentvolumeclaims?resourceVersion=451&timeoutSeconds=451&watch=true: (7m31.002764891s) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.155815   32116 reflector.go:428] github.com/openshift/origin/vendor/k8s.io/client-go/informers/factory.go:87: Watch close - *v1.PersistentVolumeClaim total 0 items received
    		I0615 18:36:17.156596   32116 get.go:238] Starting watch for /api/v1/persistentvolumeclaims, rv=451 labels= fields= timeout=5m57s
    		I0615 18:36:17.157337   32116 wrap.go:42] GET /api/v1/configmaps?resourceVersion=451&timeoutSeconds=451&watch=true: (7m31.001670283s) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.157495   32116 reflector.go:428] github.com/openshift/origin/vendor/k8s.io/client-go/informers/factory.go:87: Watch close - *v1.ConfigMap total 523 items received
    		I0615 18:36:17.158154   32116 get.go:238] Starting watch for /api/v1/configmaps, rv=1415 labels= fields= timeout=6m2s
    		I0615 18:36:17.230712   32116 wrap.go:42] GET /api/v1/namespaces/default: (1.166156ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48412]
    		I0615 18:36:17.232121   32116 wrap.go:42] GET /api/v1/namespaces/kube-system/configmaps/openshift-master-controllers: (1.14771ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.232194   32116 wrap.go:42] GET /api/v1/namespaces/default/services/kubernetes: (1.094482ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48412]
    		I0615 18:36:17.235608   32116 wrap.go:42] PUT /api/v1/namespaces/kube-system/configmaps/openshift-master-controllers: (2.910466ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.236182   32116 leaderelection.go:199] successfully renewed lease kube-system/openshift-master-controllers
    		I0615 18:36:17.650085   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.673518ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.650586   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (3.2602ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.650740   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.421592ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.650771   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.815639ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.650877   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.960146ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.650946   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (3.073714ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.651112   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (3.785782ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.652811   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (950.017µs) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.671841   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (984.465µs) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.787135   32116 wrap.go:42] GET /api/v1/namespaces/kube-system/configmaps/kube-scheduler: (1.534667ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:48036]
    		I0615 18:36:17.790706   32116 wrap.go:42] PUT /api/v1/namespaces/kube-system/configmaps/kube-scheduler: (2.889596ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:48036]
    		I0615 18:36:17.790927   32116 leaderelection.go:199] successfully renewed lease kube-system/kube-scheduler
    		I0615 18:36:17.944164   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.474434ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.944389   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.674336ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.953018   32116 wrap.go:42] GET /apis/extensions/v1beta1/ingresses?resourceVersion=421&timeoutSeconds=452&watch=true: (7m32.000727997s) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:48036]
    		I0615 18:36:17.953202   32116 reflector.go:428] github.com/openshift/origin/vendor/k8s.io/client-go/informers/factory.go:87: Watch close - *v1beta1.Ingress total 0 items received
    		I0615 18:36:17.953887   32116 get.go:238] Starting watch for /apis/extensions/v1beta1/ingresses, rv=421 labels= fields= timeout=7m13s
    		I0615 18:36:17.970345   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.849799ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.970599   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.440246ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.970659   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.458359ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.970810   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.097668ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.970921   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.93786ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:17.975797   32116 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.026007ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:18.024096   32116 wrap.go:42] GET /apis/oauth.openshift.io/v1/oauthaccesstokens/2dgo52EBJ0Yf-ip1kD4FYQ3EyXE0UUIe-fYdTw56_oE: (1.289387ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		I0615 18:36:18.025784   32116 wrap.go:42] GET /apis/user.openshift.io/v1/users/username: (1.115594ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48036]
    		E0615 18:36:18.026021   32116 authentication.go:63] Unable to authenticate the request due to an error: [invalid bearer token, [invalid bearer token, token timed out]]
    		I0615 18:36:18.026105   32116 wrap.go:42] GET /apis/user.openshift.io/v1/users/~: (3.728184ms) 401 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:48778]
    		INFO: 2018/06/15 18:36:18 ccBalancerWrapper: updating state and picker called by balancer: IDLE, 0xc43b10c660
    		INFO: 2018/06/15 18:36:18 dialing to target with scheme: ""
    		INFO: 2018/06/15 18:36:18 could not get resolver for scheme: ""
    		INFO: 2018/06/15 18:36:18 balancerWrapper: is pickfirst: false
    		INFO: 2018/06/15 18:36:18 balancerWrapper: got update addr from Notify: [{127.0.0.1:22680 <nil>}]
    		INFO: 2018/06/15 18:36:18 ccBalancerWrapper: new subconn: [{127.0.0.1:22680 0  <nil>}]
    		INFO: 2018/06/15 18:36:18 balancerWrapper: handle subconn state change: 0xc432d6b0c0, CONNECTING
    		INFO: 2018/06/15 18:36:18 ccBalancerWrapper: updating state and picker called by balancer: CONNECTING, 0xc43b10c660
    		INFO: 2018/06/15 18:36:18 balancerWrapper: handle subconn state change: 0xc432d6b0c0, READY
    		INFO: 2018/06/15 18:36:18 ccBalancerWrapper: updating state and picker called by balancer: READY, 0xc43b10c660
    		INFO: 2018/06/15 18:36:18 balancerWrapper: got update addr from Notify: [{127.0.0.1:22680 <nil>}]
    		
    --- PASS: TestIntegration/TestAlwaysPullImagesOn (37.29s)
    	runner_test.go:187: 
    		
    		=== OUTPUT
    		) kubernetes/b81c8f8] 127.0.0.1:45494]
    		I0615 18:36:17.359812    1191 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (851.358µs) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45494]
    		I0615 18:36:17.369125    1191 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.043036ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45494]
    		I0615 18:36:17.381784    1191 request.go:485] Throttling request took 61.435887ms, request: POST:https://127.0.0.1:23602/api/v1/namespaces/openshift-infra/secrets
    		I0615 18:36:17.385779    1191 wrap.go:42] POST /api/v1/namespaces/openshift-infra/secrets: (2.168882ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.421381    1191 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/serviceaccounts/default: (6.49556ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.446312    1191 request.go:485] Throttling request took 60.225142ms, request: POST:https://127.0.0.1:23602/api/v1/namespaces/openshift-node/secrets
    		I0615 18:36:17.449627    1191 wrap.go:42] POST /api/v1/namespaces/openshift-node/secrets: (2.72223ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.481697    1191 wrap.go:42] PUT /api/v1/namespaces/openshift-node/serviceaccounts/default: (2.935997ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.510768    1191 request.go:485] Throttling request took 60.51502ms, request: POST:https://127.0.0.1:23602/api/v1/namespaces/integration/secrets
    		I0615 18:36:17.513169    1191 wrap.go:42] POST /api/v1/namespaces/integration/secrets: (2.169003ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.536554    1191 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.259172ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45494]
    		I0615 18:36:17.545899    1191 wrap.go:42] PUT /api/v1/namespaces/integration/serviceaccounts/default: (2.504501ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.575294    1191 request.go:485] Throttling request took 61.726926ms, request: POST:https://127.0.0.1:23602/api/v1/namespaces/integration/secrets
    		I0615 18:36:17.577804    1191 wrap.go:42] POST /api/v1/namespaces/integration/secrets: (2.165102ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.610665    1191 wrap.go:42] PUT /api/v1/namespaces/integration/serviceaccounts/builder: (2.695495ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.647101    1191 request.go:485] Throttling request took 68.996235ms, request: POST:https://127.0.0.1:23602/api/v1/namespaces/integration/secrets
    		I0615 18:36:17.651028    1191 wrap.go:42] POST /api/v1/namespaces/integration/secrets: (2.614585ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.675359    1191 wrap.go:42] PUT /api/v1/namespaces/integration/serviceaccounts/deployer: (2.94636ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:45768]
    		I0615 18:36:17.707920    1191 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.307713ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45494]
    		I0615 18:36:18.119234    1191 wrap.go:42] GET /api/v1/namespaces/integration/serviceaccounts/default: (1.447111ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45806]
    		I0615 18:36:18.121457    1191 wrap.go:42] GET /api/v1/namespaces/integration/secrets/default-token-g79gw: (1.707888ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45806]
    		I0615 18:36:18.123261    1191 wrap.go:42] GET /api/v1/namespaces/integration/secrets/default-dockercfg-27d6q: (1.103731ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45806]
    		I0615 18:36:18.126062    1191 wrap.go:42] GET /api/v1/namespaces/integration/limitranges: (1.184975ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45494]
    		I0615 18:36:18.126404    1191 admission.go:97] getting security context constraints for pod  (generate: test) in namespace integration with user info &{system:admin  [system:masters system:cluster-admins system:authenticated] map[]}
    		I0615 18:36:18.126483    1191 admission.go:108] getting security context constraints for pod  (generate: test) with service account info &{system:serviceaccount:integration:default  [system:serviceaccounts system:serviceaccounts:integration] map[]}
    		I0615 18:36:18.128678    1191 wrap.go:42] GET /api/v1/namespaces/integration: (1.118219ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45494]
    		I0615 18:36:18.128901    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.128938    1191 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:18.128947    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.128956    1191 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:18.128975    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.128986    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.129000    1191 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:18.129008    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.129015    1191 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:18.129026    1191 matcher.go:342] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:18.129044    1191 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:18.129053    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.129060    1191 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:18.129080    1191 admission.go:217] validating pod  (generate: test) against providers anyuid,restricted,nonroot,hostmount-anyuid,hostnetwork,hostaccess,privileged
    		I0615 18:36:18.129167    1191 admission.go:170] pod  (generate: test) validated against provider anyuid
    		I0615 18:36:18.142793    1191 wrap.go:42] POST /api/v1/namespaces/integration/pods: (18.848824ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45806]
    		I0615 18:36:18.144518    1191 factory.go:1147] About to try and schedule pod testmwb2q
    		I0615 18:36:18.144533    1191 scheduler.go:439] Attempting to schedule pod: integration/testmwb2q
    		I0615 18:36:18.144555    1191 scheduler.go:191] Failed to schedule pod: integration/testmwb2q
    		I0615 18:36:18.144608    1191 factory.go:1262] Unable to schedule integration testmwb2q: no nodes are registered to the cluster; waiting
    		I0615 18:36:18.144643    1191 factory.go:1375] Updating pod condition for integration/testmwb2q to (PodScheduled==False)
    		I0615 18:36:18.145022    1191 backoff_utils.go:79] Backing off 1s
    		I0615 18:36:18.145270    1191 pvc_protection_controller.go:276] Got event on pod integration/testmwb2q
    		I0615 18:36:18.145445    1191 taint_manager.go:345] Noticed pod update: types.NamespacedName{Namespace:"integration", Name:"testmwb2q"}
    		I0615 18:36:18.145547    1191 disruption.go:328] addPod called on pod "testmwb2q"
    		I0615 18:36:18.145562    1191 disruption.go:403] No PodDisruptionBudgets found for pod testmwb2q, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:18.145570    1191 disruption.go:331] No matching pdb for pod "testmwb2q"
    		I0615 18:36:18.164166    1191 wrap.go:42] POST /api/v1/namespaces/integration/events: (17.201165ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:45494]
    		I0615 18:36:18.164814    1191 wrap.go:42] PUT /api/v1/namespaces/integration/pods/testmwb2q/status: (18.94257ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/scheduler] 127.0.0.1:45494]
    		I0615 18:36:18.166812    1191 pvc_protection_controller.go:276] Got event on pod integration/testmwb2q
    		I0615 18:36:18.166899    1191 disruption.go:340] updatePod called on pod "testmwb2q"
    		I0615 18:36:18.166912    1191 disruption.go:403] No PodDisruptionBudgets found for pod testmwb2q, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:18.166920    1191 disruption.go:343] No matching pdb for pod "testmwb2q"
    		I0615 18:36:18.167564    1191 factory.go:1147] About to try and schedule pod testmwb2q
    		I0615 18:36:18.167577    1191 scheduler.go:439] Attempting to schedule pod: integration/testmwb2q
    		I0615 18:36:18.167594    1191 scheduler.go:191] Failed to schedule pod: integration/testmwb2q
    		I0615 18:36:18.167626    1191 factory.go:1262] Unable to schedule integration testmwb2q: no nodes are registered to the cluster; waiting
    		I0615 18:36:18.167658    1191 factory.go:1375] Updating pod condition for integration/testmwb2q to (PodScheduled==False)
    		W0615 18:36:18.168392    1191 factory.go:1304] Request for pod integration/testmwb2q already in flight, abandoning
    		I0615 18:36:18.173416    1191 resource_quota_monitor.go:352] QuotaMonitor process object: /v1, Resource=pods, namespace integration, name testmwb2q, uid fdf67aca-70ca-11e8-b84e-0242ac110002, event type update
    		I0615 18:36:18.173569    1191 factory.go:1147] About to try and schedule pod testmwb2q
    		I0615 18:36:18.173596    1191 scheduler.go:435] Skip schedule deleting pod: integration/testmwb2q
    		I0615 18:36:18.173632    1191 pvc_protection_controller.go:276] Got event on pod integration/testmwb2q
    		I0615 18:36:18.173757    1191 disruption.go:340] updatePod called on pod "testmwb2q"
    		I0615 18:36:18.173773    1191 disruption.go:403] No PodDisruptionBudgets found for pod testmwb2q, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:18.173780    1191 disruption.go:343] No matching pdb for pod "testmwb2q"
    		I0615 18:36:18.176230    1191 resource_quota_monitor.go:352] QuotaMonitor process object: /v1, Resource=pods, namespace integration, name testmwb2q, uid fdf67aca-70ca-11e8-b84e-0242ac110002, event type update
    		I0615 18:36:18.188606    1191 wrap.go:42] DELETE /api/v1/namespaces/integration/pods/testmwb2q: (40.659024ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45806]
    		I0615 18:36:18.188888    1191 deployment_controller.go:357] Pod testmwb2q deleted.
    		I0615 18:36:18.189020    1191 resource_quota_monitor.go:352] QuotaMonitor process object: /v1, Resource=pods, namespace integration, name testmwb2q, uid fdf67aca-70ca-11e8-b84e-0242ac110002, event type delete
    		I0615 18:36:18.189107    1191 pvc_protection_controller.go:276] Got event on pod integration/testmwb2q
    		I0615 18:36:18.189136    1191 resource_quota_monitor.go:352] QuotaMonitor process object: /v1, Resource=pods, namespace integration, name testmwb2q, uid fdf67aca-70ca-11e8-b84e-0242ac110002, event type delete
    		I0615 18:36:18.189188    1191 taint_manager.go:338] Noticed pod deletion: types.NamespacedName{Namespace:"integration", Name:"testmwb2q"}
    		I0615 18:36:18.189233    1191 disruption.go:369] deletePod called on pod "testmwb2q"
    		I0615 18:36:18.189245    1191 disruption.go:403] No PodDisruptionBudgets found for pod testmwb2q, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:18.189252    1191 disruption.go:372] No matching pdb for pod "testmwb2q"
    		I0615 18:36:18.190022    1191 wrap.go:42] PATCH /api/v1/namespaces/integration/events/testmwb2q.1538693b96b3c0bf: (21.457733ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:45494]
    		I0615 18:36:18.190688    1191 admission.go:97] getting security context constraints for pod  (generate: test) in namespace integration with user info &{system:admin  [system:masters system:cluster-admins system:authenticated] map[]}
    		I0615 18:36:18.190730    1191 admission.go:108] getting security context constraints for pod  (generate: test) with service account info &{system:serviceaccount:integration:default  [system:serviceaccounts system:serviceaccounts:integration] map[]}
    		I0615 18:36:18.204119    1191 wrap.go:42] GET /api/v1/namespaces/integration: (12.330832ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45494]
    		I0615 18:36:18.204344    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.204375    1191 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:18.204384    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.204393    1191 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:18.204410    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.204420    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.204460    1191 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:18.204469    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.204477    1191 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:18.204489    1191 matcher.go:342] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:18.204509    1191 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:18.204518    1191 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:18.204525    1191 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:18.204543    1191 admission.go:217] validating pod  (generate: test) against providers anyuid,restricted,nonroot,hostmount-anyuid,hostnetwork,hostaccess,privileged
    		I0615 18:36:18.204595    1191 admission.go:170] pod  (generate: test) validated against provider anyuid
    		I0615 18:36:18.206837    1191 wrap.go:42] POST /api/v1/namespaces/integration/events: (16.181491ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:45494]
    		I0615 18:36:18.220038    1191 wrap.go:42] POST /api/v1/namespaces/integration/pods: (30.067814ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45806]
    		INFO: 2018/06/15 18:36:18 ccBalancerWrapper: updating state and picker called by balancer: IDLE, 0xc42be54900
    		INFO: 2018/06/15 18:36:18 dialing to target with scheme: ""
    		INFO: 2018/06/15 18:36:18 could not get resolver for scheme: ""
    		INFO: 2018/06/15 18:36:18 balancerWrapper: is pickfirst: false
    		INFO: 2018/06/15 18:36:18 balancerWrapper: got update addr from Notify: [{127.0.0.1:10752 <nil>}]
    		INFO: 2018/06/15 18:36:18 ccBalancerWrapper: new subconn: [{127.0.0.1:10752 0  <nil>}]
    		INFO: 2018/06/15 18:36:18 balancerWrapper: handle subconn state change: 0xc42d2b3500, CONNECTING
    		INFO: 2018/06/15 18:36:18 ccBalancerWrapper: updating state and picker called by balancer: CONNECTING, 0xc42be54900
    		I0615 18:36:18.222317    1191 factory.go:1147] About to try and schedule pod testm4chc
    		I0615 18:36:18.222330    1191 scheduler.go:439] Attempting to schedule pod: integration/testm4chc
    		I0615 18:36:18.222347    1191 scheduler.go:191] Failed to schedule pod: integration/testm4chc
    		I0615 18:36:18.222371    1191 factory.go:1262] Unable to schedule integration testm4chc: no nodes are registered to the cluster; waiting
    		I0615 18:36:18.222402    1191 factory.go:1375] Updating pod condition for integration/testm4chc to (PodScheduled==False)
    		I0615 18:36:18.228692    1191 pvc_protection_controller.go:276] Got event on pod integration/testm4chc
    		I0615 18:36:18.228752    1191 taint_manager.go:345] Noticed pod update: types.NamespacedName{Namespace:"integration", Name:"testm4chc"}
    		I0615 18:36:18.228797    1191 disruption.go:328] addPod called on pod "testm4chc"
    		I0615 18:36:18.228808    1191 disruption.go:403] No PodDisruptionBudgets found for pod testm4chc, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:18.228816    1191 disruption.go:331] No matching pdb for pod "testm4chc"
    		I0615 18:36:18.228848    1191 backoff_utils.go:79] Backing off 1s
    		I0615 18:36:18.232391    1191 wrap.go:42] PUT /api/v1/namespaces/integration/pods/testm4chc/status: (3.233079ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/scheduler] 127.0.0.1:45494]
    		I0615 18:36:18.233123    1191 pvc_protection_controller.go:276] Got event on pod integration/testm4chc
    		I0615 18:36:18.233187    1191 disruption.go:340] updatePod called on pod "testm4chc"
    		I0615 18:36:18.233199    1191 disruption.go:403] No PodDisruptionBudgets found for pod testm4chc, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:18.233207    1191 disruption.go:343] No matching pdb for pod "testm4chc"
    		I0615 18:36:18.233976    1191 factory.go:1147] About to try and schedule pod testm4chc
    		I0615 18:36:18.233989    1191 scheduler.go:439] Attempting to schedule pod: integration/testm4chc
    		I0615 18:36:18.234006    1191 scheduler.go:191] Failed to schedule pod: integration/testm4chc
    		I0615 18:36:18.234025    1191 factory.go:1262] Unable to schedule integration testm4chc: no nodes are registered to the cluster; waiting
    		I0615 18:36:18.234054    1191 factory.go:1375] Updating pod condition for integration/testm4chc to (PodScheduled==False)
    		W0615 18:36:18.234120    1191 factory.go:1304] Request for pod integration/testm4chc already in flight, abandoning
    		I0615 18:36:18.235714    1191 wrap.go:42] POST /api/v1/namespaces/integration/events: (5.567373ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:45494]
    		INFO: 2018/06/15 18:36:18 balancerWrapper: handle subconn state change: 0xc42d2b3500, READY
    		INFO: 2018/06/15 18:36:18 ccBalancerWrapper: updating state and picker called by balancer: READY, 0xc42be54900
    		
    --- PASS: TestIntegration/TestApiGroupPreferredVersions (30.62s)
    	runner_test.go:187: 
    			master_routes_test.go:382: Looking for build api group in server group discovery
    		
    		=== OUTPUT
    		ux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.485375    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (1.807964ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.486602    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (569.793µs) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.486835    1213 client_builder.go:233] Verified credential for build-controller/openshift-infra
    		I0615 18:36:33.488069    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/build-controller: (1.036556ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.490312    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (1.80785ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.491574    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (573.625µs) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.491836    1213 client_builder.go:233] Verified credential for build-controller/openshift-infra
    		I0615 18:36:33.493318    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/build-controller: (1.032143ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.495585    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (1.839209ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.496834    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (591.799µs) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.497105    1213 client_builder.go:233] Verified credential for build-controller/openshift-infra
    		I0615 18:36:33.497312    1213 controller_manager.go:201] Started "openshift.io/build"
    		I0615 18:36:33.497326    1213 controller_manager.go:191] Starting "openshift.io/templateinstance"
    		I0615 18:36:33.498560    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-controller: (1.026285ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.500066    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra: (1.097576ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.517141    1213 wrap.go:42] POST /api/v1/namespaces/openshift-infra/serviceaccounts: (16.574615ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.520120    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-controller: (2.22395ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		I0615 18:36:33.520901    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (2.542819ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.536038    1213 get.go:238] Starting watch for /api/v1/namespaces/openshift-infra/secrets, rv=326 labels= fields=type=kubernetes.io/service-account-token timeout=1h40m16.481160826s
    		I0615 18:36:33.543001    1213 wrap.go:42] POST /api/v1/namespaces/openshift-infra/secrets: (6.797755ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		I0615 18:36:33.551440    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets/template-instance-controller-token-r9cct: (5.32797ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.573914    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-controller: (21.735276ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.574177    1213 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-controller: (29.057395ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		I0615 18:36:33.575009    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (30.955516ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.577630    1213 client_builder.go:233] Verified credential for template-instance-controller/openshift-infra
    		I0615 18:36:33.577922    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&resourceVersion=326&watch=true: (42.293501ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.579215    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-controller: (1.242868ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.581701    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (2.047924ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.583099    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (613.743µs) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.583322    1213 client_builder.go:233] Verified credential for template-instance-controller/openshift-infra
    		I0615 18:36:33.584757    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-controller: (1.077258ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.587120    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (1.935471ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.588370    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (552.766µs) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.588627    1213 client_builder.go:233] Verified credential for template-instance-controller/openshift-infra
    		I0615 18:36:33.589998    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-controller: (1.164202ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.592297    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (1.898903ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.593596    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (577.766µs) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.596576    1213 client_builder.go:233] Verified credential for template-instance-controller/openshift-infra
    		I0615 18:36:33.596843    1213 controller_manager.go:201] Started "openshift.io/templateinstance"
    		I0615 18:36:33.596857    1213 controller_manager.go:191] Starting "openshift.io/templateinstancefinalizer"
    		I0615 18:36:33.598110    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-finalizer-controller: (1.055998ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.598366    1213 wrap.go:42] GET /api/v1/namespaces/kube-system/configmaps/kube-scheduler: (1.129086ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:45696]
    		I0615 18:36:33.599677    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra: (1.086877ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.602189    1213 wrap.go:42] PUT /api/v1/namespaces/kube-system/configmaps/kube-scheduler: (3.316692ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:45696]
    		I0615 18:36:33.602602    1213 wrap.go:42] POST /api/v1/namespaces/openshift-infra/serviceaccounts: (2.476108ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.603038    1213 leaderelection.go:199] successfully renewed lease kube-system/kube-scheduler
    		I0615 18:36:33.606292    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (2.358317ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.606544    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-finalizer-controller: (3.077014ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		I0615 18:36:33.614547    1213 get.go:238] Starting watch for /api/v1/namespaces/openshift-infra/secrets, rv=330 labels= fields=type=kubernetes.io/service-account-token timeout=1h8m5.885270629s
    		I0615 18:36:33.617046    1213 wrap.go:42] POST /api/v1/namespaces/openshift-infra/secrets: (3.753916ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		I0615 18:36:33.653657    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (19.819519ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.654349    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets/template-instance-finalizer-controller-token-n2vkd: (34.250917ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.655107    1213 wrap.go:42] GET /apis/rbac.authorization.k8s.io/v1/clusterroles/admin: (17.05772ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46328]
    		I0615 18:36:33.676027    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-finalizer-controller: (19.080581ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.676129    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (17.440842ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.676245    1213 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-finalizer-controller: (57.753815ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		I0615 18:36:33.676763    1213 wrap.go:42] GET /apis/rbac.authorization.k8s.io/v1/clusterroles/edit: (19.188518ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46328]
    		I0615 18:36:33.677802    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (59.739506ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.677900    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.836227ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.678056    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.511906ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.678153    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (3.560368ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.678530    1213 client_builder.go:233] Verified credential for template-instance-finalizer-controller/openshift-infra
    		I0615 18:36:33.678849    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&resourceVersion=330&watch=true: (64.71008ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.679525    1213 wrap.go:42] GET /apis/rbac.authorization.k8s.io/v1/clusterroles/view: (1.24187ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46328]
    		I0615 18:36:33.679989    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/template-instance-finalizer-controller: (1.094938ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.682468    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (2.053521ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.683840    1213 wrap.go:42] POST /apis/authentication.k8s.io/v1/tokenreviews: (608.434µs) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.684077    1213 client_builder.go:233] Verified credential for template-instance-finalizer-controller/openshift-infra
    		I0615 18:36:33.684300    1213 controller_manager.go:201] Started "openshift.io/templateinstancefinalizer"
    		I0615 18:36:33.684313    1213 controller_manager.go:191] Starting "openshift.io/serviceaccount"
    		I0615 18:36:33.684455    1213 templateinstance_finalizer.go:214] TemplateInstanceFinalizer controller waiting for cache sync
    		I0615 18:36:33.685575    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/serviceaccount-controller: (1.027156ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.687079    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra: (1.097325ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.689806    1213 wrap.go:42] GET /api?timeout=32s: (569.56µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46328]
    		I0615 18:36:33.691045    1213 wrap.go:42] GET /apis?timeout=32s: (810.087µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46328]
    		I0615 18:36:33.692548    1213 wrap.go:42] POST /api/v1/namespaces/openshift-infra/serviceaccounts: (4.990332ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.695418    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/serviceaccounts/serviceaccount-controller: (1.1204ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		INFO: 2018/06/15 18:36:33 ccBalancerWrapper: updating state and picker called by balancer: IDLE, 0xc42dc6e8a0
    		INFO: 2018/06/15 18:36:33 dialing to target with scheme: ""
    		INFO: 2018/06/15 18:36:33 could not get resolver for scheme: ""
    		INFO: 2018/06/15 18:36:33 balancerWrapper: is pickfirst: false
    		INFO: 2018/06/15 18:36:33 balancerWrapper: got update addr from Notify: [{127.0.0.1:26959 <nil>}]
    		INFO: 2018/06/15 18:36:33 ccBalancerWrapper: new subconn: [{127.0.0.1:26959 0  <nil>}]
    		INFO: 2018/06/15 18:36:33 balancerWrapper: handle subconn state change: 0xc424f4b500, CONNECTING
    		INFO: 2018/06/15 18:36:33 ccBalancerWrapper: updating state and picker called by balancer: CONNECTING, 0xc42dc6e8a0
    		I0615 18:36:33.715880    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.401715ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.715994    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (2.993435ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.716027    1213 wrap.go:42] POST /api/v1/namespaces/openshift-infra/secrets: (14.529009ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		I0615 18:36:33.716180    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (3.67167ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.719097    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets?fieldSelector=type%3Dkubernetes.io%2Fservice-account-token&limit=500: (5.177204ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.724583    1213 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/serviceaccounts/serviceaccount-controller: (7.618265ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:45696]
    		I0615 18:36:33.735582    1213 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets/serviceaccount-controller-token-zv26q: (13.860679ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.735862    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (15.560221ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.736019    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (16.182893ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.736174    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (14.978173ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.736322    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (14.660211ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.736480    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (17.10651ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.736619    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (13.642877ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.736753    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (14.165949ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.736878    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (14.769574ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		I0615 18:36:33.737038    1213 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (16.279267ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:45696]
    		INFO: 2018/06/15 18:36:33 balancerWrapper: handle subconn state change: 0xc424f4b500, READY
    		INFO: 2018/06/15 18:36:33 ccBalancerWrapper: updating state and picker called by balancer: READY, 0xc42dc6e8a0
    		
    --- PASS: TestIntegration/TestAggregator (32.26s)
    	runner_test.go:187: 
    		
    		=== OUTPUT
    		fra:default-rolebindings-controller] 127.0.0.1:46348]
    		I0615 18:36:50.322941    1246 request.go:485] Throttling request took 99.830241ms, request: POST:https://127.0.0.1:12294/api/v1/namespaces/openshift-infra/secrets
    		I0615 18:36:50.324824    1246 wrap.go:42] POST /api/v1/namespaces/openshift-infra/secrets: (1.657311ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:46348]
    		I0615 18:36:50.325529    1246 wrap.go:42] POST /apis/rbac.authorization.k8s.io/v1/namespaces/openshift-node/rolebindings: (13.493627ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:default-rolebindings-controller] 127.0.0.1:46348]
    		I0615 18:36:50.325943    1246 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets/horizontal-pod-autoscaler-token-jm8rp: (1.029121ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:46250]
    		I0615 18:36:50.333705    1246 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/secrets/horizontal-pod-autoscaler-token-jm8rp: (3.735469ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:46250]
    		I0615 18:36:50.337317    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (974.832µs) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.355283    1246 request.go:485] Throttling request took 126.819537ms, request: POST:https://127.0.0.1:12294/api/v1/namespaces/openshift-infra/secrets
    		I0615 18:36:50.357037    1246 wrap.go:42] POST /api/v1/namespaces/openshift-infra/secrets: (1.544513ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:46348]
    		I0615 18:36:50.358016    1246 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets/image-import-controller-token-9jszw: (903.029µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:46250]
    		I0615 18:36:50.364797    1246 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/secrets/image-import-controller-token-9jszw: (2.721793ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:46250]
    		I0615 18:36:50.387485    1246 request.go:485] Throttling request took 153.064839ms, request: POST:https://127.0.0.1:12294/api/v1/namespaces/openshift-infra/secrets
    		I0615 18:36:50.388992    1246 wrap.go:42] POST /api/v1/namespaces/openshift-infra/secrets: (1.31976ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:46348]
    		I0615 18:36:50.390581    1246 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets/image-trigger-controller-token-w86lz: (1.433298ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:46250]
    		I0615 18:36:50.397093    1246 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/secrets/image-trigger-controller-token-w86lz: (2.479983ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:46250]
    		I0615 18:36:50.419816    1246 request.go:485] Throttling request took 148.568305ms, request: POST:https://127.0.0.1:12294/api/v1/namespaces/openshift-infra/secrets
    		I0615 18:36:50.421327    1246 wrap.go:42] POST /api/v1/namespaces/openshift-infra/secrets: (1.30363ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:46348]
    		I0615 18:36:50.422350    1246 wrap.go:42] GET /api/v1/namespaces/openshift-infra/secrets/ingress-to-route-controller-token-t27s8: (870.313µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:46250]
    		I0615 18:36:50.428703    1246 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/secrets/ingress-to-route-controller-token-t27s8: (2.297986ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/tokens-controller] 127.0.0.1:46250]
    		I0615 18:36:50.452068    1246 request.go:485] Throttling request took 158.270068ms, request: PUT:https://127.0.0.1:12294/api/v1/namespaces/openshift-infra/serviceaccounts/namespace-security-allocation-controller
    		I0615 18:36:50.455931    1246 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/serviceaccounts/namespace-security-allocation-controller: (3.614201ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:46348]
    		I0615 18:36:50.456190    1246 create_dockercfg_secrets.go:444] Creating token secret "namespace-security-allocation-controller-token-vnh8d" for service account openshift-infra/namespace-security-allocation-controller
    		I0615 18:36:50.464775    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (953.558µs) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.464890    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.218119ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.464991    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.266326ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.468349    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.592868ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.468422    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.657326ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.468349    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.591172ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.468568    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.105655ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.472769    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (926.759µs) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.473375    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.101109ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.473520    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.102352ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.484240    1246 request.go:485] Throttling request took 159.151448ms, request: PUT:https://127.0.0.1:12294/api/v1/namespaces/openshift-infra/serviceaccounts/node-bootstrapper
    		I0615 18:36:50.484810    1246 wrap.go:42] GET /api?timeout=32s: (326.594µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.485495    1246 wrap.go:42] GET /apis/rbac.authorization.k8s.io/v1/clusterroles/admin: (1.540154ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.485655    1246 wrap.go:42] GET /apis?timeout=32s: (400.272µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.486781    1246 wrap.go:42] GET /api/v1?timeout=32s: (542.342µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.486996    1246 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/serviceaccounts/node-bootstrapper: (2.512418ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:46348]
    		I0615 18:36:50.487305    1246 create_dockercfg_secrets.go:444] Creating token secret "node-bootstrapper-token-lp8tk" for service account openshift-infra/node-bootstrapper
    		I0615 18:36:50.487581    1246 wrap.go:42] GET /apis/apiregistration.k8s.io/v1?timeout=32s: (277.709µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.488338    1246 wrap.go:42] GET /apis/apiregistration.k8s.io/v1beta1?timeout=32s: (338.186µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.489074    1246 wrap.go:42] GET /apis/rbac.authorization.k8s.io/v1/clusterroles/edit: (2.838909ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.489344    1246 wrap.go:42] GET /apis/extensions/v1beta1?timeout=32s: (426.992µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.489784    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.6237ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.489856    1246 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.676111ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.490242    1246 wrap.go:42] GET /apis/apps/v1?timeout=32s: (349.276µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.490742    1246 wrap.go:42] GET /apis/rbac.authorization.k8s.io/v1/clusterroles/view: (1.023231ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.491021    1246 wrap.go:42] GET /apis/apps/v1beta2?timeout=32s: (318.736µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.491721    1246 wrap.go:42] GET /apis/apps/v1beta1?timeout=32s: (301.957µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.492613    1246 wrap.go:42] GET /apis/events.k8s.io/v1beta1?timeout=32s: (409.093µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.493236    1246 wrap.go:42] GET /apis/authentication.k8s.io/v1?timeout=32s: (229.057µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.494052    1246 wrap.go:42] GET /apis/authentication.k8s.io/v1beta1?timeout=32s: (355.197µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.494768    1246 wrap.go:42] GET /apis/authorization.k8s.io/v1?timeout=32s: (285.588µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.495178    1246 wrap.go:42] GET /api/v1/namespaces/default: (1.422167ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.495559    1246 wrap.go:42] GET /apis/authorization.k8s.io/v1beta1?timeout=32s: (303.878µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.496161    1246 wrap.go:42] GET /apis/autoscaling/v1?timeout=32s: (251.884µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.497073    1246 wrap.go:42] GET /apis/autoscaling/v2beta1?timeout=32s: (354.27µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.497337    1246 wrap.go:42] GET /api/v1/namespaces/default: (1.032838ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.497780    1246 wrap.go:42] GET /apis/batch/v1?timeout=32s: (265.756µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.497981    1246 wrap.go:42] GET /apis/project.openshift.io/v1/projects/default: (2.249781ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.498441    1246 wrap.go:42] GET /apis/batch/v1beta1?timeout=32s: (261.917µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.499592    1246 wrap.go:42] GET /apis/certificates.k8s.io/v1beta1?timeout=32s: (362.234µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.500403    1246 wrap.go:42] GET /apis/networking.k8s.io/v1?timeout=32s: (269.612µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.501516    1246 wrap.go:42] GET /api/v1/namespaces/default: (1.912014ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.501849    1246 wrap.go:42] GET /apis/project.openshift.io/v1/projects/default: (2.761049ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.502043    1246 wrap.go:42] GET /apis/policy/v1beta1?timeout=32s: (308.454µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.502674    1246 wrap.go:42] GET /api/v1/namespaces/default: (895.284µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46276]
    		I0615 18:36:50.502920    1246 wrap.go:42] GET /apis/authorization.openshift.io/v1?timeout=32s: (446.253µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.503804    1246 wrap.go:42] GET /apis/rbac.authorization.k8s.io/v1?timeout=32s: (427.101µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.503808    1246 wrap.go:42] GET /apis/apiregistration.k8s.io/v1beta1/apiservices/v1.: (1.498769ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.504201    1246 wrap.go:42] GET /api/v1/namespaces/default/services/kubernetes: (1.12756ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46276]
    		I0615 18:36:50.504660    1246 wrap.go:42] GET /apis/rbac.authorization.k8s.io/v1beta1?timeout=32s: (402.571µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.505274    1246 wrap.go:42] GET /apis/apiregistration.k8s.io/v1beta1/apiservices/v1.project.openshift.io: (950.765µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.505472    1246 wrap.go:42] GET /apis/storage.k8s.io/v1?timeout=32s: (352.001µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.506178    1246 wrap.go:42] GET /apis/storage.k8s.io/v1beta1?timeout=32s: (368.673µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.506913    1246 wrap.go:42] GET /apis/admissionregistration.k8s.io/v1beta1?timeout=32s: (339.063µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.507542    1246 wrap.go:42] GET /apis/apiregistration.k8s.io/v1beta1/apiservices/v1beta1.rbac.authorization.k8s.io: (1.73161ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46350]
    		I0615 18:36:50.507940    1246 wrap.go:42] GET /apis/apiextensions.k8s.io/v1beta1?timeout=32s: (353.104µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		INFO: 2018/06/15 18:36:50 ccBalancerWrapper: updating state and picker called by balancer: IDLE, 0xc43b802180
    		INFO: 2018/06/15 18:36:50 dialing to target with scheme: ""
    		INFO: 2018/06/15 18:36:50 could not get resolver for scheme: ""
    		I0615 18:36:50.508855    1246 wrap.go:42] GET /apis/apps.openshift.io/v1?timeout=32s: (446.449µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		INFO: 2018/06/15 18:36:50 balancerWrapper: is pickfirst: false
    		INFO: 2018/06/15 18:36:50 balancerWrapper: got update addr from Notify: [{127.0.0.1:28134 <nil>}]
    		INFO: 2018/06/15 18:36:50 ccBalancerWrapper: new subconn: [{127.0.0.1:28134 0  <nil>}]
    		INFO: 2018/06/15 18:36:50 balancerWrapper: handle subconn state change: 0xc42824ce90, CONNECTING
    		INFO: 2018/06/15 18:36:50 ccBalancerWrapper: updating state and picker called by balancer: CONNECTING, 0xc43b802180
    		I0615 18:36:50.510237    1246 wrap.go:42] GET /apis/build.openshift.io/v1?timeout=32s: (436.051µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.510943    1246 wrap.go:42] GET /apis/image.openshift.io/v1?timeout=32s: (299.157µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.511691    1246 wrap.go:42] GET /apis/network.openshift.io/v1?timeout=32s: (347.634µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.512400    1246 wrap.go:42] GET /apis/oauth.openshift.io/v1?timeout=32s: (276.548µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.513194    1246 wrap.go:42] GET /apis/project.openshift.io/v1?timeout=32s: (374.351µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.513885    1246 wrap.go:42] GET /apis/quota.openshift.io/v1?timeout=32s: (308.339µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.514522    1246 wrap.go:42] GET /apis/route.openshift.io/v1?timeout=32s: (276.839µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.515149    1246 wrap.go:42] GET /apis/security.openshift.io/v1?timeout=32s: (228.505µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.515849    1246 wrap.go:42] GET /apis/template.openshift.io/v1?timeout=32s: (274.926µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.516493    1246 request.go:485] Throttling request took 159.234634ms, request: PUT:https://127.0.0.1:12294/api/v1/namespaces/openshift-infra/serviceaccounts/origin-namespace-controller
    		I0615 18:36:50.516541    1246 wrap.go:42] GET /apis/user.openshift.io/v1?timeout=32s: (290.764µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:46250]
    		I0615 18:36:50.519094    1246 wrap.go:42] PUT /api/v1/namespaces/openshift-infra/serviceaccounts/origin-namespace-controller: (2.370647ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:46348]
    		INFO: 2018/06/15 18:36:50 balancerWrapper: handle subconn state change: 0xc42824ce90, READY
    		INFO: 2018/06/15 18:36:50 ccBalancerWrapper: updating state and picker called by balancer: READY, 0xc43b802180
    		I0615 18:36:50.519300    1246 create_dockercfg_secrets.go:444] Creating token secret "origin-namespace-controller-token-m2m58" for service account openshift-infra/origin-namespace-controller
    		INFO: 2018/06/15 18:36:50 balancerWrapper: got update addr from Notify: [{127.0.0.1:28134 <nil>}]
    		
    --- PASS: TestIntegration/TestAllowedSCCViaRBAC (41.39s)
    	runner_test.go:187: 
    		
    		=== OUTPUT
    		 preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace project1
    		I0615 18:36:51.069852    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.069858    1225 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace project1
    		I0615 18:36:51.069876    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.069884    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.069893    1225 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace project1
    		I0615 18:36:51.069902    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.069907    1225 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace project1
    		I0615 18:36:51.069915    1225 matcher.go:342] got preallocated value for groups: 1000060000/10000 in namespace project1
    		I0615 18:36:51.069930    1225 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace project1
    		I0615 18:36:51.069944    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.069953    1225 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace project1
    		I0615 18:36:51.069974    1225 admission.go:217] validating pod test3 (generate: ) against providers anyuid,restricted,nonroot,hostmount-anyuid,hostnetwork,hostaccess,privileged
    		I0615 18:36:51.070103    1225 admission.go:170] pod test3 (generate: ) validated against provider hostaccess
    		I0615 18:36:51.071694    1225 wrap.go:42] POST /api/v1/namespaces/project1/pods: (4.685667ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43774]
    		I0615 18:36:51.072025    1225 factory.go:1147] About to try and schedule pod test3
    		I0615 18:36:51.072036    1225 scheduler.go:439] Attempting to schedule pod: project1/test3
    		I0615 18:36:51.072051    1225 scheduler.go:191] Failed to schedule pod: project1/test3
    		I0615 18:36:51.072090    1225 factory.go:1262] Unable to schedule project1 test3: no nodes are registered to the cluster; waiting
    		I0615 18:36:51.072115    1225 factory.go:1375] Updating pod condition for project1/test3 to (PodScheduled==False)
    		I0615 18:36:51.072142    1225 pvc_protection_controller.go:276] Got event on pod project1/test3
    		I0615 18:36:51.072246    1225 disruption.go:328] addPod called on pod "test3"
    		I0615 18:36:51.072262    1225 disruption.go:403] No PodDisruptionBudgets found for pod test3, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:51.072270    1225 disruption.go:331] No matching pdb for pod "test3"
    		I0615 18:36:51.072300    1225 taint_manager.go:345] Noticed pod update: types.NamespacedName{Namespace:"project1", Name:"test3"}
    		I0615 18:36:51.072335    1225 backoff_utils.go:79] Backing off 1s
    		I0615 18:36:51.072942    1225 admission.go:97] getting security context constraints for pod test4 (generate: ) in namespace project2 with user info &{user1 0d1dfcc1-70cb-11e8-8549-0242ac110002 [system:authenticated:oauth system:authenticated] map[scopes.authorization.openshift.io:[]]}
    		I0615 18:36:51.073565    1225 admission.go:108] getting security context constraints for pod test4 (generate: ) with service account info &{system:serviceaccount:project2:default  [system:serviceaccounts system:serviceaccounts:project2] map[]}
    		I0615 18:36:51.074305    1225 wrap.go:42] PUT /api/v1/namespaces/project1/pods/test3/status: (1.899002ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/scheduler] 127.0.0.1:43458]
    		I0615 18:36:51.074422    1225 disruption.go:340] updatePod called on pod "test3"
    		I0615 18:36:51.074457    1225 disruption.go:403] No PodDisruptionBudgets found for pod test3, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:51.074465    1225 disruption.go:343] No matching pdb for pod "test3"
    		I0615 18:36:51.074479    1225 pvc_protection_controller.go:276] Got event on pod project1/test3
    		I0615 18:36:51.074778    1225 factory.go:1147] About to try and schedule pod test3
    		I0615 18:36:51.074790    1225 scheduler.go:439] Attempting to schedule pod: project1/test3
    		I0615 18:36:51.074801    1225 scheduler.go:191] Failed to schedule pod: project1/test3
    		I0615 18:36:51.074817    1225 factory.go:1262] Unable to schedule project1 test3: no nodes are registered to the cluster; waiting
    		I0615 18:36:51.074840    1225 factory.go:1375] Updating pod condition for project1/test3 to (PodScheduled==False)
    		W0615 18:36:51.074882    1225 factory.go:1304] Request for pod project1/test3 already in flight, abandoning
    		I0615 18:36:51.075725    1225 wrap.go:42] GET /api/v1/namespaces/project2: (1.307224ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43458]
    		I0615 18:36:51.075928    1225 matcher.go:279] got preallocated values for min: 1000070000, max: 1000079999 for uid range in namespace project2
    		I0615 18:36:51.075945    1225 matcher.go:292] got preallocated value for level: s0:c8,c7 for selinux options in namespace project2
    		I0615 18:36:51.075953    1225 matcher.go:322] got preallocated value for groups: 1000070000/10000 in namespace project2
    		I0615 18:36:51.075971    1225 admission.go:217] validating pod test4 (generate: ) against providers restricted
    		I0615 18:36:51.076033    1225 admission.go:179] unable to validate pod test4 (generate: ) against any security context constraint: [provider restricted: .spec.securityContext.hostPID: Invalid value: true: Host PID is not allowed to be used spec.containers[0].securityContext.hostPID: Invalid value: true: Host PID is not allowed to be used]
    		I0615 18:36:51.076166    1225 wrap.go:42] POST /api/v1/namespaces/project2/pods: (3.702289ms) 403 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43774]
    		I0615 18:36:51.076376    1225 wrap.go:42] POST /api/v1/namespaces/project1/events: (3.779238ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:43458]
    		I0615 18:36:51.077106    1225 admission.go:97] getting security context constraints for pod test5 (generate: ) in namespace project1 with user info &{user2 0d27c8de-70cb-11e8-8549-0242ac110002 [system:authenticated:oauth system:authenticated] map[scopes.authorization.openshift.io:[]]}
    		I0615 18:36:51.077379    1225 admission.go:108] getting security context constraints for pod test5 (generate: ) with service account info &{system:serviceaccount:project1:default  [system:serviceaccounts system:serviceaccounts:project1] map[]}
    		I0615 18:36:51.079269    1225 wrap.go:42] GET /api/v1/namespaces/project1: (967.147µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43458]
    		I0615 18:36:51.079574    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.079603    1225 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace project1
    		I0615 18:36:51.079612    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.079620    1225 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace project1
    		I0615 18:36:51.079636    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.079647    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.079662    1225 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace project1
    		I0615 18:36:51.079681    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.079689    1225 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace project1
    		I0615 18:36:51.079703    1225 matcher.go:342] got preallocated value for groups: 1000060000/10000 in namespace project1
    		I0615 18:36:51.079736    1225 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace project1
    		I0615 18:36:51.079753    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.079762    1225 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace project1
    		I0615 18:36:51.079789    1225 admission.go:217] validating pod test5 (generate: ) against providers anyuid,restricted,nonroot,hostmount-anyuid,hostnetwork,hostaccess,privileged
    		I0615 18:36:51.079981    1225 admission.go:170] pod test5 (generate: ) validated against provider hostaccess
    		I0615 18:36:51.082108    1225 wrap.go:42] PATCH /api/v1/namespaces/project1/events/test3.1538694341552a8b: (4.811002ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:43458]
    		I0615 18:36:51.082275    1225 wrap.go:42] POST /api/v1/namespaces/project1/pods: (5.566299ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43774]
    		I0615 18:36:51.082497    1225 disruption.go:328] addPod called on pod "test5"
    		I0615 18:36:51.082517    1225 disruption.go:403] No PodDisruptionBudgets found for pod test5, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:51.082525    1225 disruption.go:331] No matching pdb for pod "test5"
    		I0615 18:36:51.082535    1225 factory.go:1147] About to try and schedule pod test5
    		I0615 18:36:51.082560    1225 scheduler.go:439] Attempting to schedule pod: project1/test5
    		I0615 18:36:51.082563    1225 pvc_protection_controller.go:276] Got event on pod project1/test5
    		I0615 18:36:51.082576    1225 scheduler.go:191] Failed to schedule pod: project1/test5
    		I0615 18:36:51.082600    1225 factory.go:1262] Unable to schedule project1 test5: no nodes are registered to the cluster; waiting
    		I0615 18:36:51.082632    1225 factory.go:1375] Updating pod condition for project1/test5 to (PodScheduled==False)
    		I0615 18:36:51.082541    1225 taint_manager.go:345] Noticed pod update: types.NamespacedName{Namespace:"project1", Name:"test5"}
    		I0615 18:36:51.082706    1225 backoff_utils.go:79] Backing off 1s
    		I0615 18:36:51.083377    1225 admission.go:97] getting security context constraints for pod test6 (generate: ) in namespace project2 with user info &{user2 0d27c8de-70cb-11e8-8549-0242ac110002 [system:authenticated:oauth system:authenticated] map[scopes.authorization.openshift.io:[]]}
    		I0615 18:36:51.083671    1225 admission.go:108] getting security context constraints for pod test6 (generate: ) with service account info &{system:serviceaccount:project2:default  [system:serviceaccounts system:serviceaccounts:project2] map[]}
    		I0615 18:36:51.084483    1225 wrap.go:42] PUT /api/v1/namespaces/project1/pods/test5/status: (1.588834ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/scheduler] 127.0.0.1:43458]
    		I0615 18:36:51.084778    1225 disruption.go:340] updatePod called on pod "test5"
    		I0615 18:36:51.084791    1225 disruption.go:403] No PodDisruptionBudgets found for pod test5, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:51.084793    1225 pvc_protection_controller.go:276] Got event on pod project1/test5
    		I0615 18:36:51.084799    1225 disruption.go:343] No matching pdb for pod "test5"
    		I0615 18:36:51.084854    1225 factory.go:1147] About to try and schedule pod test5
    		I0615 18:36:51.084874    1225 scheduler.go:439] Attempting to schedule pod: project1/test5
    		I0615 18:36:51.084887    1225 scheduler.go:191] Failed to schedule pod: project1/test5
    		I0615 18:36:51.084903    1225 factory.go:1262] Unable to schedule project1 test5: no nodes are registered to the cluster; waiting
    		I0615 18:36:51.084923    1225 factory.go:1375] Updating pod condition for project1/test5 to (PodScheduled==False)
    		W0615 18:36:51.084955    1225 factory.go:1304] Request for pod project1/test5 already in flight, abandoning
    		I0615 18:36:51.085674    1225 wrap.go:42] GET /api/v1/namespaces/project2: (933.406µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43458]
    		I0615 18:36:51.085829    1225 matcher.go:292] got preallocated value for level: s0:c8,c7 for selinux options in namespace project2
    		I0615 18:36:51.085856    1225 matcher.go:279] got preallocated values for min: 1000070000, max: 1000079999 for uid range in namespace project2
    		I0615 18:36:51.085867    1225 matcher.go:292] got preallocated value for level: s0:c8,c7 for selinux options in namespace project2
    		I0615 18:36:51.085875    1225 matcher.go:322] got preallocated value for groups: 1000070000/10000 in namespace project2
    		I0615 18:36:51.085891    1225 matcher.go:292] got preallocated value for level: s0:c8,c7 for selinux options in namespace project2
    		I0615 18:36:51.085902    1225 matcher.go:292] got preallocated value for level: s0:c8,c7 for selinux options in namespace project2
    		I0615 18:36:51.085917    1225 matcher.go:279] got preallocated values for min: 1000070000, max: 1000079999 for uid range in namespace project2
    		I0615 18:36:51.085925    1225 matcher.go:292] got preallocated value for level: s0:c8,c7 for selinux options in namespace project2
    		I0615 18:36:51.085932    1225 matcher.go:322] got preallocated value for groups: 1000070000/10000 in namespace project2
    		I0615 18:36:51.085944    1225 matcher.go:342] got preallocated value for groups: 1000070000/10000 in namespace project2
    		I0615 18:36:51.085963    1225 matcher.go:279] got preallocated values for min: 1000070000, max: 1000079999 for uid range in namespace project2
    		I0615 18:36:51.085972    1225 matcher.go:292] got preallocated value for level: s0:c8,c7 for selinux options in namespace project2
    		I0615 18:36:51.085979    1225 matcher.go:322] got preallocated value for groups: 1000070000/10000 in namespace project2
    		I0615 18:36:51.085996    1225 admission.go:217] validating pod test6 (generate: ) against providers anyuid,restricted,nonroot,hostmount-anyuid,hostnetwork,hostaccess,privileged
    		I0615 18:36:51.086180    1225 admission.go:170] pod test6 (generate: ) validated against provider hostaccess
    		I0615 18:36:51.086469    1225 wrap.go:42] POST /api/v1/namespaces/project1/events: (3.441822ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:43458]
    		I0615 18:36:51.087675    1225 wrap.go:42] POST /api/v1/namespaces/project2/pods: (4.78483ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43774]
    		I0615 18:36:51.087775    1225 disruption.go:328] addPod called on pod "test6"
    		I0615 18:36:51.087790    1225 disruption.go:403] No PodDisruptionBudgets found for pod test6, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:51.087797    1225 disruption.go:331] No matching pdb for pod "test6"
    		I0615 18:36:51.087814    1225 taint_manager.go:345] Noticed pod update: types.NamespacedName{Namespace:"project2", Name:"test6"}
    		I0615 18:36:51.087841    1225 pvc_protection_controller.go:276] Got event on pod project2/test6
    		I0615 18:36:51.088005    1225 factory.go:1147] About to try and schedule pod test6
    		I0615 18:36:51.088016    1225 scheduler.go:439] Attempting to schedule pod: project2/test6
    		I0615 18:36:51.088030    1225 scheduler.go:191] Failed to schedule pod: project2/test6
    		I0615 18:36:51.088044    1225 factory.go:1262] Unable to schedule project2 test6: no nodes are registered to the cluster; waiting
    		I0615 18:36:51.088070    1225 factory.go:1375] Updating pod condition for project2/test6 to (PodScheduled==False)
    		I0615 18:36:51.088236    1225 backoff_utils.go:79] Backing off 1s
    		I0615 18:36:51.089271    1225 controller.go:537] quota admission added evaluator for: {security.openshift.io podsecuritypolicyselfsubjectreviews}
    		I0615 18:36:51.090882    1225 wrap.go:42] PATCH /api/v1/namespaces/project1/events/test5.1538694341f59e59: (3.906499ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:43458]
    		I0615 18:36:51.091113    1225 wrap.go:42] PUT /api/v1/namespaces/project2/pods/test6/status: (2.775303ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/scheduler] 127.0.0.1:43458]
    		I0615 18:36:51.091420    1225 disruption.go:340] updatePod called on pod "test6"
    		I0615 18:36:51.091457    1225 disruption.go:403] No PodDisruptionBudgets found for pod test6, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:51.091465    1225 disruption.go:343] No matching pdb for pod "test6"
    		I0615 18:36:51.091489    1225 pvc_protection_controller.go:276] Got event on pod project2/test6
    		I0615 18:36:51.091616    1225 wrap.go:42] GET /api/v1/namespaces/project1: (1.666127ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43458]
    		I0615 18:36:51.091760    1225 factory.go:1147] About to try and schedule pod test6
    		I0615 18:36:51.091776    1225 scheduler.go:439] Attempting to schedule pod: project2/test6
    		I0615 18:36:51.091792    1225 scheduler.go:191] Failed to schedule pod: project2/test6
    		I0615 18:36:51.091808    1225 factory.go:1262] Unable to schedule project2 test6: no nodes are registered to the cluster; waiting
    		I0615 18:36:51.091834    1225 factory.go:1375] Updating pod condition for project2/test6 to (PodScheduled==False)
    		W0615 18:36:51.091875    1225 factory.go:1304] Request for pod project2/test6 already in flight, abandoning
    		I0615 18:36:51.091920    1225 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace project1
    		I0615 18:36:51.092110    1225 wrap.go:42] POST /apis/security.openshift.io/v1/namespaces/project1/podsecuritypolicyselfsubjectreviews: (3.537265ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43774]
    		I0615 18:36:51.094013    1225 wrap.go:42] POST /api/v1/namespaces/project2/events: (2.264476ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:43458]
    		I0615 18:36:51.094594    1225 wrap.go:42] GET /api/v1/namespaces/project2: (890.978µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43458]
    		I0615 18:36:51.094804    1225 matcher.go:292] got preallocated value for level: s0:c8,c7 for selinux options in namespace project2
    		I0615 18:36:51.094958    1225 wrap.go:42] POST /apis/security.openshift.io/v1/namespaces/project2/podsecuritypolicyselfsubjectreviews: (2.234791ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:43774]
    		INFO: 2018/06/15 18:36:51 ccBalancerWrapper: updating state and picker called by balancer: IDLE, 0xc42e7ad380
    		INFO: 2018/06/15 18:36:51 dialing to target with scheme: ""
    		INFO: 2018/06/15 18:36:51 could not get resolver for scheme: ""
    		INFO: 2018/06/15 18:36:51 balancerWrapper: is pickfirst: false
    		INFO: 2018/06/15 18:36:51 balancerWrapper: got update addr from Notify: [{127.0.0.1:12476 <nil>}]
    		INFO: 2018/06/15 18:36:51 ccBalancerWrapper: new subconn: [{127.0.0.1:12476 0  <nil>}]
    		INFO: 2018/06/15 18:36:51 balancerWrapper: handle subconn state change: 0xc428787f30, CONNECTING
    		INFO: 2018/06/15 18:36:51 ccBalancerWrapper: updating state and picker called by balancer: CONNECTING, 0xc42e7ad380
    		I0615 18:36:51.097381    1225 wrap.go:42] PATCH /api/v1/namespaces/project2/events/test6.1538694342489e14: (2.792917ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:43458]
    		INFO: 2018/06/15 18:36:51 balancerWrapper: handle subconn state change: 0xc428787f30, READY
    		INFO: 2018/06/15 18:36:51 ccBalancerWrapper: updating state and picker called by balancer: READY, 0xc42e7ad380
    		INFO: 2018/06/15 18:36:51 balancerWrapper: got update addr from Notify: [{127.0.0.1:12476 <nil>}]
    		
    --- PASS: TestIntegration/TestAlwaysPullImagesOff (36.84s)
    	runner_test.go:187: 
    		
    		=== OUTPUT
    		0.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.401418    1238 request.go:485] Throttling request took 62.587995ms, request: POST:https://127.0.0.1:10619/api/v1/namespaces/openshift-node/secrets
    		I0615 18:36:54.403242    1238 wrap.go:42] POST /api/v1/namespaces/openshift-node/secrets: (1.611772ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.435835    1238 wrap.go:42] PUT /api/v1/namespaces/openshift-node/serviceaccounts/deployer: (1.981335ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.465974    1238 request.go:485] Throttling request took 62.410683ms, request: POST:https://127.0.0.1:10619/api/v1/namespaces/integration/secrets
    		I0615 18:36:54.468026    1238 wrap.go:42] POST /api/v1/namespaces/integration/secrets: (1.685464ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.500653    1238 wrap.go:42] PUT /api/v1/namespaces/integration/serviceaccounts/builder: (2.023324ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.529280    1238 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (795.321µs) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59750]
    		I0615 18:36:54.530579    1238 request.go:485] Throttling request took 62.297368ms, request: POST:https://127.0.0.1:10619/api/v1/namespaces/integration/secrets
    		I0615 18:36:54.534538    1238 wrap.go:42] POST /api/v1/namespaces/integration/secrets: (3.633738ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.564852    1238 wrap.go:42] PUT /api/v1/namespaces/integration/serviceaccounts/default: (1.960385ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.595007    1238 request.go:485] Throttling request took 60.1665ms, request: POST:https://127.0.0.1:10619/api/v1/namespaces/integration/secrets
    		I0615 18:36:54.596773    1238 wrap.go:42] POST /api/v1/namespaces/integration/secrets: (1.537655ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.629346    1238 wrap.go:42] PUT /api/v1/namespaces/integration/serviceaccounts/deployer: (1.945323ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/system:serviceaccount:openshift-infra:serviceaccount-pull-secrets-controller] 127.0.0.1:59918]
    		I0615 18:36:54.819684    1238 wrap.go:42] GET /api/v1/namespaces/kube-system/configmaps/kube-controller-manager: (1.279562ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:59750]
    		I0615 18:36:54.822335    1238 wrap.go:42] PUT /api/v1/namespaces/kube-system/configmaps/kube-controller-manager: (2.133953ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:59750]
    		I0615 18:36:54.822556    1238 leaderelection.go:199] successfully renewed lease kube-system/kube-controller-manager
    		I0615 18:36:54.839166    1238 wrap.go:42] GET /api/v1/namespaces/integration/serviceaccounts/default: (1.002879ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59922]
    		I0615 18:36:54.840798    1238 wrap.go:42] GET /api/v1/namespaces/integration/secrets/default-token-t5sl6: (1.152212ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59922]
    		I0615 18:36:54.842179    1238 wrap.go:42] GET /api/v1/namespaces/integration/secrets/default-dockercfg-75c5n: (893.573µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59922]
    		I0615 18:36:54.844397    1238 wrap.go:42] GET /api/v1/namespaces/integration/limitranges: (865.932µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59750]
    		I0615 18:36:54.844754    1238 admission.go:97] getting security context constraints for pod  (generate: test) in namespace integration with user info &{system:admin  [system:masters system:cluster-admins system:authenticated] map[]}
    		I0615 18:36:54.844804    1238 admission.go:108] getting security context constraints for pod  (generate: test) with service account info &{system:serviceaccount:integration:default  [system:serviceaccounts system:serviceaccounts:integration] map[]}
    		I0615 18:36:54.846457    1238 wrap.go:42] GET /api/v1/namespaces/integration: (866.897µs) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59750]
    		I0615 18:36:54.846699    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.846743    1238 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:54.846753    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.846762    1238 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:54.846793    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.846808    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.846824    1238 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:54.846835    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.846843    1238 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:54.846860    1238 matcher.go:342] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:54.846887    1238 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:54.846898    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.846906    1238 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:54.846934    1238 admission.go:217] validating pod  (generate: test) against providers anyuid,restricted,nonroot,hostmount-anyuid,hostnetwork,hostaccess,privileged
    		I0615 18:36:54.847004    1238 admission.go:170] pod  (generate: test) validated against provider anyuid
    		I0615 18:36:54.848654    1238 wrap.go:42] POST /api/v1/namespaces/integration/pods: (5.928963ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59922]
    		I0615 18:36:54.848947    1238 factory.go:1147] About to try and schedule pod testx7jl8
    		I0615 18:36:54.848961    1238 scheduler.go:439] Attempting to schedule pod: integration/testx7jl8
    		I0615 18:36:54.848983    1238 scheduler.go:191] Failed to schedule pod: integration/testx7jl8
    		I0615 18:36:54.849041    1238 factory.go:1262] Unable to schedule integration testx7jl8: no nodes are registered to the cluster; waiting
    		I0615 18:36:54.849085    1238 disruption.go:328] addPod called on pod "testx7jl8"
    		I0615 18:36:54.849083    1238 factory.go:1375] Updating pod condition for integration/testx7jl8 to (PodScheduled==False)
    		I0615 18:36:54.849092    1238 taint_manager.go:345] Noticed pod update: types.NamespacedName{Namespace:"integration", Name:"testx7jl8"}
    		I0615 18:36:54.849106    1238 disruption.go:403] No PodDisruptionBudgets found for pod testx7jl8, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:54.849115    1238 disruption.go:331] No matching pdb for pod "testx7jl8"
    		I0615 18:36:54.849130    1238 pvc_protection_controller.go:276] Got event on pod integration/testx7jl8
    		I0615 18:36:54.849170    1238 backoff_utils.go:79] Backing off 1s
    		I0615 18:36:54.853084    1238 store.go:370] GuaranteedUpdate of /kubernetes.io/pods/integration/testx7jl8 failed because of a conflict, going to retry
    		I0615 18:36:54.853349    1238 wrap.go:42] POST /api/v1/namespaces/integration/events: (3.710057ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:59750]
    		I0615 18:36:54.853843    1238 disruption.go:340] updatePod called on pod "testx7jl8"
    		I0615 18:36:54.853869    1238 disruption.go:403] No PodDisruptionBudgets found for pod testx7jl8, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:54.853877    1238 disruption.go:343] No matching pdb for pod "testx7jl8"
    		I0615 18:36:54.853886    1238 wrap.go:42] PUT /api/v1/namespaces/integration/pods/testx7jl8/status: (4.414814ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/scheduler] 127.0.0.1:59750]
    		I0615 18:36:54.853908    1238 pvc_protection_controller.go:276] Got event on pod integration/testx7jl8
    		I0615 18:36:54.854243    1238 factory.go:1147] About to try and schedule pod testx7jl8
    		I0615 18:36:54.854257    1238 scheduler.go:439] Attempting to schedule pod: integration/testx7jl8
    		I0615 18:36:54.854268    1238 scheduler.go:191] Failed to schedule pod: integration/testx7jl8
    		I0615 18:36:54.854279    1238 factory.go:1262] Unable to schedule integration testx7jl8: no nodes are registered to the cluster; waiting
    		I0615 18:36:54.854302    1238 factory.go:1375] Updating pod condition for integration/testx7jl8 to (PodScheduled==False)
    		W0615 18:36:54.854379    1238 factory.go:1304] Request for pod integration/testx7jl8 already in flight, abandoning
    		I0615 18:36:54.854930    1238 factory.go:1147] About to try and schedule pod testx7jl8
    		I0615 18:36:54.854961    1238 scheduler.go:435] Skip schedule deleting pod: integration/testx7jl8
    		I0615 18:36:54.855200    1238 resource_quota_monitor.go:352] QuotaMonitor process object: /v1, Resource=pods, namespace integration, name testx7jl8, uid 13d92c42-70cb-11e8-9818-0242ac110002, event type update
    		I0615 18:36:54.855215    1238 disruption.go:340] updatePod called on pod "testx7jl8"
    		I0615 18:36:54.855226    1238 disruption.go:403] No PodDisruptionBudgets found for pod testx7jl8, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:54.855233    1238 disruption.go:343] No matching pdb for pod "testx7jl8"
    		I0615 18:36:54.855260    1238 pvc_protection_controller.go:276] Got event on pod integration/testx7jl8
    		I0615 18:36:54.855287    1238 resource_quota_monitor.go:352] QuotaMonitor process object: /v1, Resource=pods, namespace integration, name testx7jl8, uid 13d92c42-70cb-11e8-9818-0242ac110002, event type update
    		I0615 18:36:54.856691    1238 wrap.go:42] DELETE /api/v1/namespaces/integration/pods/testx7jl8: (7.201161ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59922]
    		I0615 18:36:54.856770    1238 resource_quota_monitor.go:352] QuotaMonitor process object: /v1, Resource=pods, namespace integration, name testx7jl8, uid 13d92c42-70cb-11e8-9818-0242ac110002, event type delete
    		I0615 18:36:54.856851    1238 deployment_controller.go:357] Pod testx7jl8 deleted.
    		I0615 18:36:54.856932    1238 taint_manager.go:338] Noticed pod deletion: types.NamespacedName{Namespace:"integration", Name:"testx7jl8"}
    		I0615 18:36:54.856961    1238 pvc_protection_controller.go:276] Got event on pod integration/testx7jl8
    		I0615 18:36:54.856982    1238 resource_quota_monitor.go:352] QuotaMonitor process object: /v1, Resource=pods, namespace integration, name testx7jl8, uid 13d92c42-70cb-11e8-9818-0242ac110002, event type delete
    		I0615 18:36:54.857015    1238 disruption.go:369] deletePod called on pod "testx7jl8"
    		I0615 18:36:54.857025    1238 disruption.go:403] No PodDisruptionBudgets found for pod testx7jl8, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:54.857032    1238 disruption.go:372] No matching pdb for pod "testx7jl8"
    		I0615 18:36:54.857743    1238 admission.go:97] getting security context constraints for pod  (generate: test) in namespace integration with user info &{system:admin  [system:masters system:cluster-admins system:authenticated] map[]}
    		I0615 18:36:54.857798    1238 admission.go:108] getting security context constraints for pod  (generate: test) with service account info &{system:serviceaccount:integration:default  [system:serviceaccounts system:serviceaccounts:integration] map[]}
    		I0615 18:36:54.859695    1238 wrap.go:42] GET /api/v1/namespaces/integration: (1.090438ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59750]
    		I0615 18:36:54.859870    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.859890    1238 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:54.859896    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.859901    1238 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:54.859912    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.859918    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.859926    1238 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:54.859930    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.859935    1238 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:54.859942    1238 matcher.go:342] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:54.859957    1238 matcher.go:279] got preallocated values for min: 1000060000, max: 1000069999 for uid range in namespace integration
    		I0615 18:36:54.859962    1238 matcher.go:292] got preallocated value for level: s0:c8,c2 for selinux options in namespace integration
    		I0615 18:36:54.859967    1238 matcher.go:322] got preallocated value for groups: 1000060000/10000 in namespace integration
    		I0615 18:36:54.859976    1238 admission.go:217] validating pod  (generate: test) against providers anyuid,restricted,nonroot,hostmount-anyuid,hostnetwork,hostaccess,privileged
    		I0615 18:36:54.860003    1238 admission.go:170] pod  (generate: test) validated against provider anyuid
    		I0615 18:36:54.860284    1238 wrap.go:42] PATCH /api/v1/namespaces/integration/events/testx7jl8.1538694422751474: (5.039273ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:59750]
    		I0615 18:36:54.861518    1238 wrap.go:42] POST /api/v1/namespaces/integration/pods: (4.384401ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59922]
    		I0615 18:36:54.861827    1238 taint_manager.go:345] Noticed pod update: types.NamespacedName{Namespace:"integration", Name:"testsfd9n"}
    		I0615 18:36:54.861848    1238 pvc_protection_controller.go:276] Got event on pod integration/testsfd9n
    		I0615 18:36:54.861851    1238 factory.go:1147] About to try and schedule pod testsfd9n
    		I0615 18:36:54.861860    1238 scheduler.go:439] Attempting to schedule pod: integration/testsfd9n
    		I0615 18:36:54.861865    1238 disruption.go:328] addPod called on pod "testsfd9n"
    		I0615 18:36:54.861874    1238 disruption.go:403] No PodDisruptionBudgets found for pod testsfd9n, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:54.861881    1238 disruption.go:331] No matching pdb for pod "testsfd9n"
    		I0615 18:36:54.861874    1238 scheduler.go:191] Failed to schedule pod: integration/testsfd9n
    		I0615 18:36:54.861906    1238 factory.go:1262] Unable to schedule integration testsfd9n: no nodes are registered to the cluster; waiting
    		I0615 18:36:54.861932    1238 factory.go:1375] Updating pod condition for integration/testsfd9n to (PodScheduled==False)
    		I0615 18:36:54.862092    1238 backoff_utils.go:79] Backing off 1s
    		INFO: 2018/06/15 18:36:54 ccBalancerWrapper: updating state and picker called by balancer: IDLE, 0xc43e71b6e0
    		INFO: 2018/06/15 18:36:54 dialing to target with scheme: ""
    		INFO: 2018/06/15 18:36:54 could not get resolver for scheme: ""
    		INFO: 2018/06/15 18:36:54 balancerWrapper: is pickfirst: false
    		INFO: 2018/06/15 18:36:54 balancerWrapper: got update addr from Notify: [{127.0.0.1:10420 <nil>}]
    		INFO: 2018/06/15 18:36:54 ccBalancerWrapper: new subconn: [{127.0.0.1:10420 0  <nil>}]
    		INFO: 2018/06/15 18:36:54 balancerWrapper: handle subconn state change: 0xc42afa2b40, CONNECTING
    		INFO: 2018/06/15 18:36:54 ccBalancerWrapper: updating state and picker called by balancer: CONNECTING, 0xc43e71b6e0
    		I0615 18:36:54.863902    1238 wrap.go:42] PUT /api/v1/namespaces/integration/pods/testsfd9n/status: (1.660383ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/scheduler] 127.0.0.1:59750]
    		I0615 18:36:54.864252    1238 disruption.go:340] updatePod called on pod "testsfd9n"
    		I0615 18:36:54.864263    1238 disruption.go:403] No PodDisruptionBudgets found for pod testsfd9n, PodDisruptionBudget controller will avoid syncing.
    		I0615 18:36:54.864268    1238 disruption.go:343] No matching pdb for pod "testsfd9n"
    		I0615 18:36:54.864280    1238 pvc_protection_controller.go:276] Got event on pod integration/testsfd9n
    		I0615 18:36:54.864502    1238 factory.go:1147] About to try and schedule pod testsfd9n
    		I0615 18:36:54.864515    1238 scheduler.go:439] Attempting to schedule pod: integration/testsfd9n
    		I0615 18:36:54.864531    1238 scheduler.go:191] Failed to schedule pod: integration/testsfd9n
    		I0615 18:36:54.864546    1238 factory.go:1262] Unable to schedule integration testsfd9n: no nodes are registered to the cluster; waiting
    		I0615 18:36:54.864571    1238 factory.go:1375] Updating pod condition for integration/testsfd9n to (PodScheduled==False)
    		W0615 18:36:54.864603    1238 factory.go:1304] Request for pod integration/testsfd9n already in flight, abandoning
    		I0615 18:36:54.864903    1238 wrap.go:42] POST /api/v1/namespaces/integration/events: (4.191778ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:59750]
    		I0615 18:36:54.867657    1238 wrap.go:42] POST /api/v1/namespaces/integration/events: (2.330508ms) 201 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:59750]
    		I0615 18:36:54.871514    1238 wrap.go:42] PATCH /api/v1/namespaces/integration/events/testsfd9n.15386944233925c6: (3.224152ms) 200 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8/leader-election] 127.0.0.1:59750]
    		I0615 18:36:54.871760    1238 wrap.go:42] GET /api/v1/namespaces/openshift-web-console/configmaps/webconsole-config: (1.140744ms) 404 [[integration.test/v1.10.0+b81c8f8 (linux/amd64) kubernetes/b81c8f8] 127.0.0.1:59750]
    		INFO: 2018/06/15 18:36:54 balancerWrapper: handle subconn state change: 0xc42afa2b40, READY
    		INFO: 2018/06/15 18:36:54 ccBalancerWrapper: updating state and picker called by balancer: READY, 0xc43e71b6e0
    		INFO: 2018/06/15 18:36:54 balancerWrapper: got update addr from Notify: [{127.0.0.1:10420 <nil>}]
    		
PASS
ok  	github.com/openshift/origin/test/integration/runner	1891.051s
[INFO] [18:36:55+0000] jUnit XML report placed at _output/scripts/test-integration/artifacts/gotest_report_FnAuZ.xml
Of 203 tests executed in 1891.051s, 203 succeeded, 0 failed, and 0 were skipped.
[INFO] [18:36:55+0000] hack/test-go.sh exited with code 0 after 00h 31m 32s
[WARNING] [18:36:56+0000] Copying _output/local/releases from the container failed!
[WARNING] [18:36:56+0000] Error response from daemon: lstat /var/lib/docker/overlay2/a49b08f947b38516c27b79c4e6e74f0097c4d9b8c6346c5a3b916bf59aac5db9/merged/go/src/github.com/openshift/origin/_output/local/releases: no such file or directory
+ set +o xtrace
########## FINISHED STAGE: SUCCESS: RUN INTEGRATION TESTS [00h 43m 07s] ##########
[PostBuildScript] - Executing post build scripts.
[workspace] $ /bin/bash /tmp/jenkins6044153371190035187.sh
########## STARTING STAGE: DOWNLOAD ARTIFACTS FROM THE REMOTE HOST ##########
+ [[ -s /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ export PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
+ trap 'exit 0' EXIT
++ pwd
+ ARTIFACT_DIR=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/gathered
+ rm -rf /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/gathered
+ mkdir -p /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/gathered
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo stat /data/src/github.com/openshift/origin/_output/scripts
  File: ‘/data/src/github.com/openshift/origin/_output/scripts’
  Size: 61        	Blocks: 0          IO Block: 4096   directory
Device: ca02h/51714d	Inode: 184771268   Links: 5
Access: (2755/drwxr-sr-x)  Uid: ( 1001/  origin)   Gid: ( 1003/origin-git)
Context: unconfined_u:object_r:container_file_t:s0
Access: 1970-01-01 00:00:00.000000000 +0000
Modify: 2018-06-15 17:55:02.000000000 +0000
Change: 2018-06-15 18:36:56.274578918 +0000
 Birth: -
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo chmod -R o+rX /data/src/github.com/openshift/origin/_output/scripts
+ scp -r -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel:/data/src/github.com/openshift/origin/_output/scripts /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/gathered
+ tree /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/gathered
/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/gathered
└── scripts
    ├── shell
    │   ├── artifacts
    │   ├── logs
    │   │   ├── 82d1a60ab91020163023bab1b6446d7855708e6bea0fa0376884d7c2a6a79115.json
    │   │   └── scripts.log
    │   └── openshift.local.home
    ├── test-integration
    │   ├── artifacts
    │   │   ├── gotest_report_FnAuZ
    │   │   └── gotest_report_FnAuZ.xml
    │   ├── logs
    │   │   ├── raw_test_output.log
    │   │   ├── scripts.log
    │   │   └── test-go-err.log
    │   └── openshift.local.home
    └── test-tools
        ├── artifacts
        ├── logs
        │   ├── raw_test_output.log
        │   └── scripts.log
        └── openshift.local.home

13 directories, 9 files
+ exit 0
[workspace] $ /bin/bash /tmp/jenkins8588708627632753332.sh
########## STARTING STAGE: GENERATE ARTIFACTS FROM THE REMOTE HOST ##########
+ [[ -s /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ export PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
+ trap 'exit 0' EXIT
++ pwd
+ ARTIFACT_DIR=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/generated
+ rm -rf /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/generated
+ mkdir /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/generated
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo docker version && sudo docker info && sudo docker images && sudo docker ps -a 2>&1'
  WARNING: You're not using the default seccomp profile
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo cat /etc/sysconfig/docker /etc/sysconfig/docker-network /etc/sysconfig/docker-storage /etc/sysconfig/docker-storage-setup /etc/systemd/system/docker.service 2>&1'
+ true
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo find /var/lib/docker/containers -name *.log | sudo xargs tail -vn +1 2>&1'
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'oc get --raw /metrics --server=https://$( uname --nodename ):10250 --config=/etc/origin/master/admin.kubeconfig 2>&1'
+ true
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo ausearch -m AVC -m SELINUX_ERR -m USER_AVC 2>&1'
+ true
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'oc get --raw /metrics --config=/etc/origin/master/admin.kubeconfig 2>&1'
+ true
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo df -T -h && sudo pvs && sudo vgs && sudo lvs && sudo findmnt --all 2>&1'
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo yum list installed 2>&1'
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo journalctl --dmesg --no-pager --all --lines=all 2>&1'
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel 'sudo journalctl _PID=1 --no-pager --all --lines=all 2>&1'
+ tree /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/generated
/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/generated
├── avc_denials.log
├── containers.log
├── dmesg.log
├── docker.config
├── docker.info
├── filesystem.info
├── installed_packages.log
├── master-metrics.log
├── node-metrics.log
└── pid1.journal

0 directories, 10 files
+ exit 0
[workspace] $ /bin/bash /tmp/jenkins6476305536926630087.sh
########## STARTING STAGE: FETCH SYSTEMD JOURNALS FROM THE REMOTE HOST ##########
+ [[ -s /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ export PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
+ trap 'exit 0' EXIT
++ pwd
+ ARTIFACT_DIR=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/journals
+ rm -rf /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/journals
+ mkdir /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/journals
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo journalctl --unit docker.service --no-pager --all --lines=all
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo journalctl --unit dnsmasq.service --no-pager --all --lines=all
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config openshiftdevel sudo journalctl --unit systemd-journald.service --no-pager --all --lines=all
+ tree /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/journals
/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/artifacts/journals
├── dnsmasq.service
├── docker.service
└── systemd-journald.service

0 directories, 3 files
+ exit 0
[workspace] $ /bin/bash /tmp/jenkins1835413521482807635.sh
########## STARTING STAGE: ASSEMBLE GCS OUTPUT ##########
+ [[ -s /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ export PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
+ trap 'exit 0' EXIT
+ mkdir -p gcs/artifacts gcs/artifacts/generated gcs/artifacts/journals gcs/artifacts/gathered
++ python -c 'import json; import urllib; print json.load(urllib.urlopen('\''https://ci.openshift.redhat.com/jenkins/job/test_branch_origin_integration/3265/api/json'\''))['\''result'\'']'
+ result=SUCCESS
+ cat
++ date +%s
+ cat /var/lib/jenkins/jobs/test_branch_origin_integration/builds/3265/log
+ cp artifacts/generated/avc_denials.log artifacts/generated/containers.log artifacts/generated/dmesg.log artifacts/generated/docker.config artifacts/generated/docker.info artifacts/generated/filesystem.info artifacts/generated/installed_packages.log artifacts/generated/master-metrics.log artifacts/generated/node-metrics.log artifacts/generated/pid1.journal gcs/artifacts/generated/
+ cp artifacts/journals/dnsmasq.service artifacts/journals/docker.service artifacts/journals/systemd-journald.service gcs/artifacts/journals/
+ cp -r artifacts/gathered/scripts gcs/artifacts/
++ pwd
+ scp -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config -r /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/gcs openshiftdevel:/data
+ scp -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config /var/lib/jenkins/.config/gcloud/gcs-publisher-credentials.json openshiftdevel:/data/credentials.json
+ exit 0
[workspace] $ /bin/bash /tmp/jenkins322068510025935499.sh
########## STARTING STAGE: PUSH THE ARTIFACTS AND METADATA ##########
+ [[ -s /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ export PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
++ mktemp
+ script=/tmp/tmp.pEek8gk6gu
+ cat
+ chmod +x /tmp/tmp.pEek8gk6gu
+ scp -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config /tmp/tmp.pEek8gk6gu openshiftdevel:/tmp/tmp.pEek8gk6gu
+ ssh -F /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/.ssh_config -t openshiftdevel 'bash -l -c "timeout 300 /tmp/tmp.pEek8gk6gu"'
+ cd /home/origin
+ trap 'exit 0' EXIT
+ [[ -n {"type":"postsubmit","job":"test_branch_origin_integration","buildid":"85806909-70c4-11e8-8611-0a58ac100c6c","refs":{"org":"openshift","repo":"origin","base_ref":"master","base_sha":"5fbdb8976949b33b2a627a3dfedf4e3255b9c307"}} ]]
++ jq --compact-output .buildid
+ [[ "85806909-70c4-11e8-8611-0a58ac100c6c" =~ ^"[0-9]+"$ ]]
+ echo 'Using BUILD_NUMBER'
Using BUILD_NUMBER
++ jq --compact-output '.buildid |= "3265"'
+ JOB_SPEC='{"type":"postsubmit","job":"test_branch_origin_integration","buildid":"3265","refs":{"org":"openshift","repo":"origin","base_ref":"master","base_sha":"5fbdb8976949b33b2a627a3dfedf4e3255b9c307"}}'
+ docker run -e 'JOB_SPEC={"type":"postsubmit","job":"test_branch_origin_integration","buildid":"3265","refs":{"org":"openshift","repo":"origin","base_ref":"master","base_sha":"5fbdb8976949b33b2a627a3dfedf4e3255b9c307"}}' -v /data:/data:z registry.svc.ci.openshift.org/ci/gcsupload:latest --dry-run=false --gcs-path=gs://origin-ci-test --gcs-credentials-file=/data/credentials.json --path-strategy=single --default-org=openshift --default-repo=origin /data/gcs/artifacts /data/gcs/build-log.txt /data/gcs/finished.json
Unable to find image 'registry.svc.ci.openshift.org/ci/gcsupload:latest' locally
Trying to pull repository registry.svc.ci.openshift.org/ci/gcsupload ... 
latest: Pulling from registry.svc.ci.openshift.org/ci/gcsupload
605ce1bd3f31: Already exists
dc6346da9948: Already exists
714dbeb5426b: Pulling fs layer
714dbeb5426b: Verifying Checksum
714dbeb5426b: Download complete
714dbeb5426b: Pull complete
Digest: sha256:6bc55d4011bd84c4da4bd18aaa5ff6f45a1518439f4d30dd8f873bc2437f386c
Status: Downloaded newer image for registry.svc.ci.openshift.org/ci/gcsupload:latest
{"component":"gcsupload","level":"info","msg":"Gathering artifacts from artifact directory: /data/gcs/artifacts","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/avc_denials.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/avc_denials.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/containers.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/containers.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/dmesg.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/dmesg.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/docker.config in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/docker.config\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/docker.info in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/docker.info\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/filesystem.info in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/filesystem.info\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/installed_packages.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/installed_packages.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/master-metrics.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/master-metrics.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/node-metrics.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/node-metrics.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/generated/pid1.journal in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/generated/pid1.journal\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/journals/dnsmasq.service in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/journals/dnsmasq.service\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/journals/docker.service in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/journals/docker.service\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/journals/systemd-journald.service in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/journals/systemd-journald.service\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/shell/logs/82d1a60ab91020163023bab1b6446d7855708e6bea0fa0376884d7c2a6a79115.json in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/shell/logs/82d1a60ab91020163023bab1b6446d7855708e6bea0fa0376884d7c2a6a79115.json\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/shell/logs/scripts.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/shell/logs/scripts.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/test-integration/artifacts/gotest_report_FnAuZ in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/artifacts/gotest_report_FnAuZ\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/test-integration/artifacts/gotest_report_FnAuZ.xml in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/artifacts/gotest_report_FnAuZ.xml\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/test-integration/logs/raw_test_output.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/raw_test_output.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/test-integration/logs/scripts.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/scripts.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/test-integration/logs/test-go-err.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/test-go-err.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/test-tools/logs/raw_test_output.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/test-tools/logs/raw_test_output.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","level":"info","msg":"Found /data/gcs/artifacts/scripts/test-tools/logs/scripts.log in artifact directory. Uploading as logs/test_branch_origin_integration/3265/artifacts/scripts/test-tools/logs/scripts.log\n","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/journals/systemd-journald.service","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/latest-build.txt","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/containers.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/docker.config","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/docker.info","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/shell/logs/82d1a60ab91020163023bab1b6446d7855708e6bea0fa0376884d7c2a6a79115.json","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/shell/logs/scripts.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/artifacts/gotest_report_FnAuZ","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/artifacts/gotest_report_FnAuZ.xml","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/dmesg.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/node-metrics.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/journals/dnsmasq.service","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/journals/docker.service","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/raw_test_output.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/build-log.txt","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-tools/logs/scripts.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/finished.json","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/filesystem.info","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/installed_packages.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/master-metrics.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-tools/logs/raw_test_output.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/avc_denials.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/pid1.journal","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/scripts.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/test-go-err.log","level":"info","msg":"Queued for upload","time":"2018-06-15T18:37:10Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/docker.config","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/journals/dnsmasq.service","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/docker.info","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/test-go-err.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/avc_denials.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-tools/logs/raw_test_output.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/dmesg.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/containers.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/installed_packages.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/artifacts/gotest_report_FnAuZ.xml","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/shell/logs/82d1a60ab91020163023bab1b6446d7855708e6bea0fa0376884d7c2a6a79115.json","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/finished.json","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/artifacts/gotest_report_FnAuZ","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/shell/logs/scripts.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/latest-build.txt","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/master-metrics.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/journals/systemd-journald.service","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/node-metrics.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/journals/docker.service","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/pid1.journal","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-tools/logs/scripts.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/scripts.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/generated/filesystem.info","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/build-log.txt","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","dest":"logs/test_branch_origin_integration/3265/artifacts/scripts/test-integration/logs/raw_test_output.log","level":"info","msg":"Finished upload","time":"2018-06-15T18:37:11Z"}
{"component":"gcsupload","level":"info","msg":"Finished upload to GCS","time":"2018-06-15T18:37:11Z"}
+ exit 0
+ set +o xtrace
########## FINISHED STAGE: SUCCESS: PUSH THE ARTIFACTS AND METADATA [00h 00m 05s] ##########
[workspace] $ /bin/bash /tmp/jenkins4722133260377007417.sh
########## STARTING STAGE: DEPROVISION CLOUD RESOURCES ##########
+ [[ -s /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate ]]
+ source /var/lib/jenkins/jobs/test_branch_origin_integration/workspace/activate
++ export VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ VIRTUAL_ENV=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e
++ export PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ PATH=/var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/bin:/sbin:/usr/sbin:/bin:/usr/bin
++ unset PYTHON_HOME
++ export OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
++ OCT_CONFIG_HOME=/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config
+ oct deprovision

PLAYBOOK: main.yml *************************************************************
4 plays in /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/main.yml

PLAY [ensure we have the parameters necessary to deprovision virtual hosts] ****

TASK [ensure all required variables are set] ***********************************
task path: /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/main.yml:9
skipping: [localhost] => (item=origin_ci_inventory_dir)  => {
    "changed": false, 
    "generated_timestamp": "2018-06-15 14:37:12.736617", 
    "item": "origin_ci_inventory_dir", 
    "skip_reason": "Conditional check failed", 
    "skipped": true
}
skipping: [localhost] => (item=origin_ci_aws_region)  => {
    "changed": false, 
    "generated_timestamp": "2018-06-15 14:37:12.741655", 
    "item": "origin_ci_aws_region", 
    "skip_reason": "Conditional check failed", 
    "skipped": true
}

PLAY [deprovision virtual hosts in EC2] ****************************************

TASK [Gathering Facts] *********************************************************
ok: [localhost]

TASK [deprovision a virtual EC2 host] ******************************************
task path: /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/main.yml:28
included: /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml for localhost

TASK [update the SSH configuration to remove AWS EC2 specifics] ****************
task path: /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml:2
ok: [localhost] => {
    "changed": false, 
    "generated_timestamp": "2018-06-15 14:37:13.559421", 
    "msg": ""
}

TASK [rename EC2 instance for termination reaper] ******************************
task path: /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml:8
changed: [localhost] => {
    "changed": true, 
    "generated_timestamp": "2018-06-15 14:37:14.140371", 
    "msg": "Tags {'Name': 'oct-terminate'} created for resource i-075e44df4f8c29121."
}

TASK [tear down the EC2 instance] **********************************************
task path: /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml:15
changed: [localhost] => {
    "changed": true, 
    "generated_timestamp": "2018-06-15 14:37:14.974126", 
    "instance_ids": [
        "i-075e44df4f8c29121"
    ], 
    "instances": [
        {
            "ami_launch_index": "0", 
            "architecture": "x86_64", 
            "block_device_mapping": {
                "/dev/sda1": {
                    "delete_on_termination": true, 
                    "status": "attached", 
                    "volume_id": "vol-03f447fb7dbed632b"
                }, 
                "/dev/sdb": {
                    "delete_on_termination": true, 
                    "status": "attached", 
                    "volume_id": "vol-08ee9ed34e1a798c4"
                }
            }, 
            "dns_name": "ec2-52-90-206-74.compute-1.amazonaws.com", 
            "ebs_optimized": false, 
            "groups": {
                "sg-7e73221a": "default"
            }, 
            "hypervisor": "xen", 
            "id": "i-075e44df4f8c29121", 
            "image_id": "ami-0f2178e5f060dbf2d", 
            "instance_type": "m4.xlarge", 
            "kernel": null, 
            "key_name": "libra", 
            "launch_time": "2018-06-15T17:51:01.000Z", 
            "placement": "us-east-1d", 
            "private_dns_name": "ip-172-18-7-64.ec2.internal", 
            "private_ip": "172.18.7.64", 
            "public_dns_name": "ec2-52-90-206-74.compute-1.amazonaws.com", 
            "public_ip": "52.90.206.74", 
            "ramdisk": null, 
            "region": "us-east-1", 
            "root_device_name": "/dev/sda1", 
            "root_device_type": "ebs", 
            "state": "running", 
            "state_code": 16, 
            "tags": {
                "Name": "oct-terminate", 
                "openshift_etcd": "", 
                "openshift_master": "", 
                "openshift_node": ""
            }, 
            "tenancy": "default", 
            "virtualization_type": "hvm"
        }
    ], 
    "tagged_instances": []
}

TASK [remove the serialized host variables] ************************************
task path: /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/roles/aws-down/tasks/main.yml:22
changed: [localhost] => {
    "changed": true, 
    "generated_timestamp": "2018-06-15 14:37:15.233707", 
    "path": "/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory/host_vars/172.18.7.64.yml", 
    "state": "absent"
}

PLAY [deprovision virtual hosts locally manged by Vagrant] *********************

TASK [Gathering Facts] *********************************************************
ok: [localhost]

PLAY [clean up local configuration for deprovisioned instances] ****************

TASK [remove inventory configuration directory] ********************************
task path: /var/lib/jenkins/origin-ci-tool/4b405957477ba1b70cfacd1cf43c6d41a605fc8e/lib/python2.7/site-packages/oct/ansible/oct/playbooks/deprovision/main.yml:61
changed: [localhost] => {
    "changed": true, 
    "generated_timestamp": "2018-06-15 14:37:15.714478", 
    "path": "/var/lib/jenkins/jobs/test_branch_origin_integration/workspace/.config/origin-ci-tool/inventory", 
    "state": "absent"
}

PLAY RECAP *********************************************************************
localhost                  : ok=8    changed=4    unreachable=0    failed=0   

+ set +o xtrace
########## FINISHED STAGE: SUCCESS: DEPROVISION CLOUD RESOURCES [00h 00m 04s] ##########
Archiving artifacts
[WS-CLEANUP] Deleting project workspace...[WS-CLEANUP] done
Finished: SUCCESS