search

openshift / openshift-ansible

Install and config an OpenShift 3.x cluster
https://try.openshift.com
Apache License 2.0
2.19k stars 2.32k forks source link

Could not find an allocated subnet for node #2154

Closed anhnguyenbk closed 8 years ago

anhnguyenbk commented 8 years ago

I set up a cluster for study using openshift-ansible (1 master and 1 node created by Virtualbox). The node failed at task "Start and enable node" Ansible version: 2.1.0.0 OS: Ubuntu 15.10

TASK [openshift_node : Start and enable node] **********************************
fatal: [ose3-node1.example.com]: FAILED! => {"changed": false, "failed": true, "msg": "Job for origin-node.service failed because the control process exited with error code. See \"systemctl status origin-node.service\" and \"journalctl -xe\" for details.\n"}

Here is ansible inventory

[OSEv3:children]
masters
nodes

[OSEv3:vars]
ansible_ssh_user=root
deployment_type=origin

[masters]
ose3-master.example.com

[nodes]
ose3-node1.example.com

systemctl status origin-node.service -l

h07 14 13:55:53 ose3-node1.example.com origin-node[10552]: W0714 13:55:53.522225   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:54 ose3-node1.example.com origin-node[10552]: W0714 13:55:54.026817   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:54 ose3-node1.example.com origin-node[10552]: W0714 13:55:54.531313   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:55 ose3-node1.example.com origin-node[10552]: W0714 13:55:55.037096   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:55 ose3-node1.example.com origin-node[10552]: W0714 13:55:55.541938   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:56 ose3-node1.example.com origin-node[10552]: W0714 13:55:56.047141   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:56 ose3-node1.example.com origin-node[10552]: W0714 13:55:56.551582   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:57 ose3-node1.example.com origin-node[10552]: W0714 13:55:57.063494   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:57 ose3-node1.example.com origin-node[10552]: W0714 13:55:57.569587   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 13:55:58 ose3-node1.example.com origin-node[10552]: W0714 13:55:58.083364   10552 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
detiber commented 8 years ago

@anhnguyenbk Could you provide the full log output for origin-node journalctl -u origin-node -l and also see if there are any error messages in the master service log journalctl -u origin-master -l?

anhnguyenbk commented 8 years ago

@detiber Sure journalctl -u origin-node -l

Th07 14 15:14:14 ose3-node1.example.com systemd[1]: Starting Origin Node...
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.943638    2719 plugins.go:71] No cloud provider specified.
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.944143    2719 common.go:79] Skipping loopback/non-IPv4 addr: "127.0.0.1" for node ose3-node1.example.com
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.944168    2719 common.go:77] Initializing single-tenant plugin for ose3-node1.example.com (192.168.56.120)
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.944194    2719 start_node.go:288] Starting node ose3-node1.example.com (v1.2.0)
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.951731    2719 start_node.go:297] Connecting to API server https://ose3-master.example.com:8443
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.955521    2719 node.go:131] Connecting to Docker at unix:///var/run/docker.sock
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.991752    2719 manager.go:132] cAdvisor running in container: "/"
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: I0714 15:14:15.043702    2719 iptables.go:380] running iptables -C [POSTROUTING -t nat -s 10.1.0.0/16 ! -d 10.1.0.0/16 -j MASQUERADE]
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: I0714 15:14:15.046166    2719 iptables.go:380] running iptables -C [INPUT -t filter -p udp -m multiport --dports 4789 -m comment --comment 001 vxlan incoming -j ACCEPT]
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: I0714 15:14:15.049362    2719 iptables.go:380] running iptables -C [INPUT -t filter -i tun0 -m comment --comment traffic from docker for internet -j ACCEPT]
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: I0714 15:14:15.052030    2719 iptables.go:380] running iptables -C [FORWARD -t filter -d 10.1.0.0/16 -j ACCEPT]
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: I0714 15:14:15.054634    2719 iptables.go:380] running iptables -C [FORWARD -t filter -s 10.1.0.0/16 -j ACCEPT]
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: W0714 15:14:15.061019    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: I0714 15:14:15.181995    2719 fs.go:109] Filesystem partitions: map[/dev/mapper/VolGroup00-LogVol00:{mountpoint:/ major:253 minor:0 fsType: blockSize:0} /dev/sda2:{mountpoint:/boot major:8 minor:2 fsType: blockSize:0}]
Th07 14 15:14:15 ose3-node1.example.com origin-node[2719]: W0714 15:14:15.589759    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:16 ose3-node1.example.com origin-node[2719]: W0714 15:14:16.094670    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:16 ose3-node1.example.com origin-node[2719]: W0714 15:14:16.599521    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:17 ose3-node1.example.com origin-node[2719]: W0714 15:14:17.105515    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:17 ose3-node1.example.com origin-node[2719]: W0714 15:14:17.609979    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:17 ose3-node1.example.com origin-node[2719]: I0714 15:14:17.941469    2719 manager.go:169] Machine: {NumCores:2 CpuFrequency:2394562 MemoryCapacity:1041137664 MachineID:3c9038a8f3d74c919ece895d9f886be9 SystemUUID:3C9038A8-F3D7-4C91-9ECE-895D9F886BE9 BootID:83414eb6-7e2f-4a57-964a-88448ba664db Filesystems:[{Device:/dev/mapper/VolGroup00-LogVol00 Capacity:39696318464 Type:vfs Inodes:2473984} {Device:/dev/sda2 Capacity:499337216 Type:vfs Inodes:128016}] DiskMap:map[253:2:{Name:dm-2 Major:253 Minor:2 Size:67108864 Scheduler:none} 253:3:{Name:dm-3 Major:253 Minor:3 Size:107374182400 Scheduler:none} 8:0:{Name:sda Major:8 Minor:0 Size:42949672960 Scheduler:cfq} 253:0:{Name:dm-0 Major:253 Minor:0 Size:40466644992 Scheduler:none} 253:1:{Name:dm-1 Major:253 Minor:1 Size:1610612736 Scheduler:none}] NetworkDevices:[{Name:eth0 MacAddress:52:54:00:bd:97:1e Speed:1000 Mtu:1500} {Name:eth1 MacAddress:08:00:27:df:0e:30 Speed:1000 Mtu:1500}] Topology:[{Id:0 Memory:1073274880 Cores:[{Id:0 Threads:[0] Caches:[{Size:32768 Type:Data Level:1} {Size:32768 Type:Instruction Level:1} {Size:262144 Type:Unified Level:2} {Size:3145728 Type:Unified Level:3}]} {Id:1 Threads:[1] Caches:[{Size:32768 Type:Data Level:1} {Size:32768 Type:Instruction Level:1} {Size:262144 Type:Unified Level:2} {Size:3145728 Type:Unified Level:3}]}] Caches:[]}] CloudProvider:Unknown InstanceType:Unknown InstanceID:None}
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.002463    2719 manager.go:175] Version: {KernelVersion:3.10.0-327.22.2.el7.x86_64 ContainerOsVersion:CentOS Linux 7 (Core) DockerVersion:1.10.3 CadvisorVersion: CadvisorRevision:}
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.003472    2719 server.go:344] Using root directory: /var/lib/origin/openshift.local.volumes
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.003751    2719 server.go:608] Sending events to api server.
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.003865    2719 server.go:683] Watching apiserver
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.010209    2719 plugins.go:127] Loaded network plugin "redhat/openshift-ovs-subnet"
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.010493    2719 kubelet.go:380] Hairpin mode set to "none"
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.064162    2719 config.go:269] Setting pods for source api
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: W0714 15:14:18.238863    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.256298    2719 manager.go:212] Setting dockerRoot to /var/lib/docker
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: I0714 15:14:18.256339    2719 plugins.go:56] Registering credential provider: .dockercfg
Th07 14 15:14:18 ose3-node1.example.com origin-node[2719]: W0714 15:14:18.743822    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
...
Th07 14 15:14:34 ose3-node1.example.com origin-node[2719]: W0714 15:14:34.781840    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:35 ose3-node1.example.com origin-node[2719]: W0714 15:14:35.286186    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:35 ose3-node1.example.com origin-node[2719]: W0714 15:14:35.790059    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
0714 15:14:45.007702    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:45 ose3-node1.example.com origin-node[2719]: W0714 15:14:45.513877    2719 subnets.go:110] Could not find an allocated subnet for node: ose3-node1.example.com, Waiting...
Th07 14 15:14:46 ose3-node1.example.com origin-node[2719]: F0714 15:14:46.019306    2719 node.go:310] error: SDN node startup failed: Failed to start plugin: Failed to get subnet for this host: ose3-node1.example.com, error: hostsubnets "ose3-node1.example.com" not found
Th07 14 15:14:46 ose3-node1.example.com systemd[1]: origin-node.service: main process exited, code=exited, status=255/n/a
Th07 14 15:14:46 ose3-node1.example.com systemd[1]: Failed to start Origin Node.
Th07 14 15:14:46 ose3-node1.example.com systemd[1]: Unit origin-node.service entered failed state.
Th07 14 15:14:46 ose3-node1.example.com systemd[1]: origin-node.service failed.
Th07 14 15:14:51 ose3-node1.example.com systemd[1]: origin-node.service holdoff time over, scheduling restart.
Th07 14 15:14:14 ose3-node1.example.com systemd[1]: Starting Origin Node...
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.943638    2719 plugins.go:71] No cloud provider specified.
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.944143    2719 common.go:79] Skipping loopback/non-IPv4 addr: "127.0.0.1" for node ose3-node1.example.com
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.944168    2719 common.go:77] Initializing single-tenant plugin for ose3-node1.example.com (192.168.56.120)
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.944194    2719 start_node.go:288] Starting node ose3-node1.example.com (v1.2.0)
Th07 14 15:14:14 ose3-node1.example.com origin-node[2719]: I0714 15:14:14.951731    2719 start_node.go:297] Connecting to API server https://ose3-master.example.com:8443

journalctl -u origin-master -l

-- Logs begin at Thu 2016-07-14 15:07:12 UTC, end at Thu 2016-07-14 15:24:03 UTC. --
Jul 14 15:08:08 ose3-master.example.com systemd[1]: Starting Origin Master Service...
Jul 14 15:08:30 ose3-master.example.com origin-master[990]: W0714 15:08:30.760609     990 start_master.go:270] assetConfig.loggingPublicURL: Invalid value: "": required to view aggregated container logs in the console
Jul 14 15:08:30 ose3-master.example.com origin-master[990]: W0714 15:08:30.760862     990 start_master.go:270] assetConfig.metricsPublicURL: Invalid value: "": required to view cluster metrics in the console
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.154351     990 plugins.go:71] No cloud provider specified.
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.154486     990 admission.go:67] ClusterResourceOverride admission controller loaded with config: <nil>
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.154620     990 admission.go:25] Initializing BuildDefaults plugin with config: &api.BuildDefaultsConfig{TypeMeta:unversioned.TypeMeta{Kind:"", APIVersion:""}, GitHTTPProxy:"", GitHTTPSProxy:"", Env:[]api.EnvVar(nil)}
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.154664     990 admission.go:22] Initializing BuildOverrides plugin with config: &api.BuildOverridesConfig{TypeMeta:unversioned.TypeMeta{Kind:"", APIVersion:""}, ForcePull:false}
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.420200     990 genericapiserver.go:81] Adding storage destination for group
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.420265     990 genericapiserver.go:81] Adding storage destination for group extensions
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.420309     990 start_master.go:383] Starting master on 0.0.0.0:8443 (v1.2.0)
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.420320     990 start_master.go:384] Public master address is https://ose3-master.example.com:8443
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.420350     990 start_master.go:388] Using images from "openshift/origin-<component>:v1.2.0"
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.421005     990 server.go:245] resolving ose3-master.example.com:7001 to 127.0.0.1:7001
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.421202     990 server.go:245] resolving ose3-master.example.com:4001 to 127.0.0.1:4001
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.628312     990 server.go:64] etcd: peerTLS: cert = /etc/origin/master/etcd.server.crt, key = /etc/origin/master/etcd.server.key, ca = /etc/origin/master/ca.crt, trusted-ca = , client-cert-auth = false
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.816715     990 server.go:75] etcd: listening for peers on https://0.0.0.0:7001
Jul 14 15:08:32 ose3-master.example.com origin-master[990]: I0714 15:08:32.816758     990 server.go:86] etcd: clientTLS: cert = /etc/origin/master/etcd.server.crt, key = /etc/origin/master/etcd.server.key, ca = /etc/origin/master/ca.crt, trusted-ca = , client-cert-auth = false
Jul 14 15:08:33 ose3-master.example.com origin-master[990]: I0714 15:08:33.006982     990 server.go:100] etcd: listening for client requests on https://0.0.0.0:4001
Jul 14 15:08:33 ose3-master.example.com origin-master[990]: I0714 15:08:33.793612     990 run.go:61] Started etcd at ose3-master.example.com:4001
Jul 14 15:08:33 ose3-master.example.com origin-master[990]: I0714 15:08:33.992165     990 run_components.go:204] Using default project node label selector:
Jul 14 15:08:34 ose3-master.example.com origin-master[990]: I0714 15:08:34.507645     990 genericapiserver.go:379] Setting GenericAPIServer service IP to "172.30.0.1" (read-write).
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: W0714 15:08:35.127246     990 controller.go:297] Resetting endpoints for master service "kubernetes" to &{{ } {kubernetes  default  d613389c-49c1-11e6-b29d-525400bd971e 8 0 2016-07-14 12:52:35 +0000 UTC <nil> <nil> map[] map[]} [{[{10.0.2.15 <nil>}] [] [{https 8443 TCP} {dns 8053 UDP} {dns-tcp 8053 TCP}]}]}
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.326699     990 plugin.go:27] Route plugin initialized with suffix=router.default.svc.cluster.local
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.454513     990 master.go:262] Started Kubernetes API at 0.0.0.0:8443/api/v1
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.454579     990 master.go:262] Started Kubernetes API Extensions at 0.0.0.0:8443/apis/extensions/v1beta1
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.454588     990 master.go:262] Started Origin API at 0.0.0.0:8443/oapi/v1
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.454594     990 master.go:262] Started OAuth2 API at 0.0.0.0:8443/oauth
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.454600     990 master.go:262] Started Web Console 0.0.0.0:8443/console/
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.454605     990 master.go:262] Started Swagger Schema API at 0.0.0.0:8443/swaggerapi/
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.454671     990 net.go:105] Got error &net.OpError{Op:"dial", Net:"tcp4", Addr:(*net.TCPAddr)(0xc20b0b7320), Err:0x6f}, trying again: "0.0.0.0:8443"
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.560058     990 net.go:105] Got error &net.OpError{Op:"dial", Net:"tcp4", Addr:(*net.TCPAddr)(0xc20be38c90), Err:0x6f}, trying again: "0.0.0.0:8443"
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.668828     990 net.go:105] Got error &net.OpError{Op:"dial", Net:"tcp4", Addr:(*net.TCPAddr)(0xc20be38cf0), Err:0x6f}, trying again: "0.0.0.0:8443"
Jul 14 15:08:35 ose3-master.example.com origin-master[990]: I0714 15:08:35.819840     990 ensure.go:226] Ignoring bootstrap policy file because cluster policy found
Jul 14 15:08:36 ose3-master.example.com origin-master[990]: I0714 15:08:36.233439     990 ensure.go:86] Added build-controller service accounts to the system:build-controller cluster role: <nil>
Jul 14 15:08:36 ose3-master.example.com origin-master[990]: I0714 15:08:36.740864     990 ensure.go:86] Added daemonset-controller service accounts to the system:daemonset-controller cluster role: <nil>
Jul 14 15:08:36 ose3-master.example.com origin-master[990]: I0714 15:08:36.945958     990 ensure.go:86] Added deployment-controller service accounts to the system:deployment-controller cluster role: <nil>
Jul 14 15:08:37 ose3-master.example.com origin-master[990]: I0714 15:08:37.184548     990 ensure.go:86] Added gc-controller service accounts to the system:gc-controller cluster role: <nil>
Jul 14 15:08:37 ose3-master.example.com origin-master[990]: I0714 15:08:37.379153     990 ensure.go:86] Added hpa-controller service accounts to the system:hpa-controller cluster role: <nil>
Jul 14 15:08:37 ose3-master.example.com origin-master[990]: I0714 15:08:37.612041     990 ensure.go:86] Added job-controller service accounts to the system:job-controller cluster role: <nil>
Jul 14 15:08:37 ose3-master.example.com origin-master[990]: I0714 15:08:37.857859     990 ensure.go:86] Added namespace-controller service accounts to the system:namespace-controller cluster role: <nil>
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.048822     990 ensure.go:86] Added pv-binder-controller service accounts to the system:pv-binder-controller cluster role: <nil>
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.262423     990 ensure.go:86] Added pv-provisioner-controller service accounts to the system:pv-provisioner-controller cluster role: <nil>
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.463924     990 ensure.go:86] Added pv-recycler-controller service accounts to the system:pv-recycler-controller cluster role: <nil>
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.680892     990 ensure.go:86] Added replication-controller service accounts to the system:replication-controller cluster role: <nil>
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: W0714 15:08:38.683505     990 run_components.go:179] Binding DNS on port 8053 instead of 53 (you may need to run as root and update your config), using 0.0.0.0:8053 which will not resolve from all locations
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.684158     990 net.go:105] Got error &net.OpError{Op:"dial", Net:"tcp", Addr:(*net.TCPAddr)(0xc20cc620c0), Err:0x6f}, trying again: "0.0.0.0:8053"
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.784747     990 net.go:105] Got error &net.OpError{Op:"dial", Net:"tcp", Addr:(*net.TCPAddr)(0xc209cbd5f0), Err:0x6f}, trying again: "0.0.0.0:8053"
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.890997     990 net.go:105] Got error &net.OpError{Op:"dial", Net:"tcp", Addr:(*net.TCPAddr)(0xc20c9a7fb0), Err:0x6f}, trying again: "0.0.0.0:8053"
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.991772     990 run_components.go:199] DNS listening at 0.0.0.0:8053
Jul 14 15:08:38 ose3-master.example.com origin-master[990]: I0714 15:08:38.991876     990 start_master.go:527] Controllers starting (*)
Jul 14 15:08:39 ose3-master.example.com systemd[1]: Started Origin Master Service.
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.646640     990 resource_quota_controller.go:148] Resource quota controller queued all resource quota for full calculation of usage
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.646686     990 resource_quota_controller.go:148] Resource quota controller queued all resource quota for full calculation of usage
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.646709     990 nodecontroller.go:143] Sending events to api server.
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651328     990 factory.go:155] Creating scheduler from configuration: {{ } [{MatchNodeSelector <nil>} {PodFitsResources <nil>} {PodFitsPorts <nil>} {NoDiskConflict <nil>} {Region 0xc20be84350}] [{LeastRequestedPriority 1 <nil>} {SelectorSpreadPriority 1 <nil>} {Zone 2 0xc20be848f0}] []}
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651404     990 factory.go:164] Registering predicate: MatchNodeSelector
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651431     990 plugins.go:122] Predicate type MatchNodeSelector already registered, reusing.
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651474     990 factory.go:164] Registering predicate: PodFitsResources
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651491     990 plugins.go:122] Predicate type PodFitsResources already registered, reusing.
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651514     990 factory.go:164] Registering predicate: PodFitsPorts
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651528     990 plugins.go:122] Predicate type PodFitsPorts already registered, reusing.
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651546     990 factory.go:164] Registering predicate: NoDiskConflict
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651560     990 plugins.go:122] Predicate type NoDiskConflict already registered, reusing.
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651580     990 factory.go:164] Registering predicate: Region
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651599     990 factory.go:170] Registering priority: LeastRequestedPriority
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651614     990 plugins.go:191] Priority type LeastRequestedPriority already registered, reusing.
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651638     990 factory.go:170] Registering priority: SelectorSpreadPriority
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651654     990 plugins.go:191] Priority type SelectorSpreadPriority already registered, reusing.
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651679     990 factory.go:170] Registering priority: Zone
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.651696     990 factory.go:190] creating scheduler with fit predicates 'map[MatchNodeSelector:{} PodFitsResources:{} PodFitsPorts:{} NoDiskConflict:{} Region:{}]' and priority functions 'map[LeastRequestedPriority:{} SelectorSpreadPriority:{} Zone:{}]
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.658939     990 replication_controller.go:208] Starting RC Manager
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.669842     990 horizontal.go:120] Starting HPA Controller
Jul 14 15:08:39 ose3-master.example.com origin-master[990]: I0714 15:08:39.671438     990 controller.go:211] Starting Daemon Sets controller manager
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.183879     990 trace.go:57] Trace "Get /oapi/v1/hostsubnets/ose3-node1.example.com" (started 2016-07-14 15:08:39.737281844 +0000 UTC):
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [446.561277ms] [446.561277ms] END
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.398216     990 endpoints_controller.go:277] Finished syncing service "default/kubernetes" endpoints. (3.067µs)
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.855324     990 persistentvolume_claim_binder_controller.go:454] Starting PersistentVolumeClaimBinder
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.855436     990 plugins.go:291] Loaded volume plugin "kubernetes.io/host-path"
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.855460     990 plugins.go:291] Loaded volume plugin "kubernetes.io/nfs"
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.855478     990 plugins.go:291] Loaded volume plugin "kubernetes.io/aws-ebs"
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.855496     990 plugins.go:291] Loaded volume plugin "kubernetes.io/gce-pd"
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.857520     990 plugins.go:291] Loaded volume plugin "kubernetes.io/cinder"
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.857585     990 persistentvolume_recycler_controller.go:322] Starting PersistentVolumeRecycler
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.857657     990 start_master.go:616] Started Kubernetes Controllers
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.923524     990 factory.go:467] Checking for deleted builds
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.923938     990 factory.go:552] Checking for deleted build pods
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.942583     990 namespace_controller.go:162] Finished syncing namespace "openshift-infra" (476ns)
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.943171     990 namespace_controller.go:162] Finished syncing namespace "default" (307ns)
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.943197     990 namespace_controller.go:162] Finished syncing namespace "management-infra" (160ns)
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.943210     990 namespace_controller.go:162] Finished syncing namespace "openshift" (119ns)
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.995741     990 trace.go:57] Trace "decodeNodeList *[]api.ImageStream" (started 2016-07-14 15:08:39.995853044 +0000 UTC):
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [999.85917ms] [999.85917ms] Decoded 11 nodes
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [999.860187ms] [1.017µs] END
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.995809     990 trace.go:57] Trace "decodeNodeList *[]api.ImageStream" (started 2016-07-14 15:08:39.995849466 +0000 UTC):
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [3.043µs] [3.043µs] Decoding dir /openshift.io/imagestreams/openshift START
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [999.914056ms] [999.911013ms] Decoding dir /openshift.io/imagestreams/openshift END
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [999.916019ms] [1.963µs] Decoded 1 nodes
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [999.916642ms] [623ns] END
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.995849     990 trace.go:57] Trace "List *api.ImageStreamList" (started 2016-07-14 15:08:39.672692423 +0000 UTC):
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [8.621µs] [8.621µs] About to list etcd node
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [323.154909ms] [323.146288ms] Etcd node listed
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [1.323127072s] [999.972163ms] Node list decoded
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [1.323136598s] [9.526µs] END
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: I0714 15:08:40.998621     990 trace.go:57] Trace "List /oapi/v1/imagestreams" (started 2016-07-14 15:08:39.672585934 +0000 UTC):
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [97.563µs] [97.563µs] About to List from storage
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [1.323271912s] [1.323174349s] Listing from storage done
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [1.32342809s] [156.178µs] Self-linking done
Jul 14 15:08:40 ose3-master.example.com origin-master[990]: [1.326001917s] [2.573827ms] Writing http response done (11 items)
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: [1.326002943s] [1.026µs] END
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.024860     990 scheduler.go:74] DEBUG: scheduler: queue (0):
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: []controller.bucket{controller.bucket{}, controller.bucket{}, controller.bucket{}, controller.bucket{}, controller.bucket{}}
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.024924     990 scheduler.go:79] DEBUG: scheduler: position: 1 5
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.024934     990 scheduler.go:56] DEBUG: scheduler: waiting for limit
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.025805     990 common.go:79] Skipping loopback/non-IPv4 addr: "127.0.0.1" for node ose3-master.example.com
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.025831     990 common.go:77] Initializing single-tenant plugin for ose3-master.example.com (192.168.56.110)
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.028981     990 scheduler.go:74] DEBUG: scheduler: queue (1):
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: []controller.bucket{controller.bucket{}, controller.bucket{}, controller.bucket{}, controller.bucket{}, controller.bucket{}}
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.029014     990 scheduler.go:79] DEBUG: scheduler: position: 2 5
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.029023     990 scheduler.go:56] DEBUG: scheduler: waiting for limit
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.041148     990 start_master.go:637] Started Origin Controllers
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.091479     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.093344     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.094210     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.094663     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.095114     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.095586     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.097594     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.098074     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.099036     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.099832     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.100335     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153293     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/python
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153468     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/ruby
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153526     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/jenkins
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153579     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/mariadb
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153629     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/mongodb
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153679     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/mysql
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153729     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/php
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153780     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/postgresql
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153830     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/nodejs
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153880     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/perl
Jul 14 15:08:41 ose3-master.example.com origin-master[990]: I0714 15:08:41.153930     990 controller.go:89] Updated all DeploymentConfigs for trigger on ImageStream openshift/wildfly
Jul 14 15:09:07 ose3-master.example.com origin-master[990]: I0714 15:09:07.834762     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.Job total 0 items received
Jul 14 15:09:07 ose3-master.example.com origin-master[990]: I0714 15:09:07.834859     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105749, nsec:669384336, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:07 ose3-master.example.com origin-master[990]: I0714 15:09:07.837480     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.DaemonSet total 0 items received
Jul 14 15:09:07 ose3-master.example.com origin-master[990]: I0714 15:09:07.837527     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105749, nsec:673112166, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:07 ose3-master.example.com origin-master[990]: I0714 15:09:07.848666     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.HorizontalPodAutoscaler total 0 items received
Jul 14 15:09:07 ose3-master.example.com origin-master[990]: I0714 15:09:07.848763     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105749, nsec:670443600, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:07 ose3-master.example.com origin-master[990]: I0714 15:09:07.849607     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *api.ReplicationController total 0 items received
Jul 14 15:09:07 ose3-master.example.com origin-master[990]: I0714 15:09:07.849643     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105749, nsec:660419279, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:08 ose3-master.example.com origin-master[990]: I0714 15:09:08.428983     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *api.Service total 0 items received
Jul 14 15:09:08 ose3-master.example.com origin-master[990]: I0714 15:09:08.429096     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105749, nsec:673580208, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:09 ose3-master.example.com origin-master[990]: I0714 15:09:09.434053     990 endpoints_controller.go:277] Finished syncing service "default/kubernetes" endpoints. (3.912µs)
Jul 14 15:09:36 ose3-master.example.com origin-master[990]: I0714 15:09:36.855807     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.DaemonSet total 0 items received
Jul 14 15:09:36 ose3-master.example.com origin-master[990]: I0714 15:09:36.855915     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105778, nsec:844406141, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:36 ose3-master.example.com origin-master[990]: I0714 15:09:36.855811     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.Job total 0 items received
Jul 14 15:09:36 ose3-master.example.com origin-master[990]: I0714 15:09:36.855972     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105778, nsec:844323027, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:36 ose3-master.example.com origin-master[990]: I0714 15:09:36.862516     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.HorizontalPodAutoscaler total 0 items received
Jul 14 15:09:36 ose3-master.example.com origin-master[990]: I0714 15:09:36.862614     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105778, nsec:853781210, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:36 ose3-master.example.com origin-master[990]: I0714 15:09:36.862911     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *api.ReplicationController total 0 items received
Jul 14 15:09:36 ose3-master.example.com origin-master[990]: I0714 15:09:36.862938     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105778, nsec:853787554, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:37 ose3-master.example.com origin-master[990]: I0714 15:09:37.436859     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *api.Service total 0 items received
Jul 14 15:09:37 ose3-master.example.com origin-master[990]: I0714 15:09:37.436958     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105779, nsec:429893392, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:09:38 ose3-master.example.com origin-master[990]: I0714 15:09:38.441855     990 endpoints_controller.go:277] Finished syncing service "default/kubernetes" endpoints. (6.495µs)
Jul 14 15:09:39 ose3-master.example.com origin-master[990]: I0714 15:09:39.037573     990 reflector.go:366] pkg/project/controller/factory.go:37: Watch close - *api.Namespace total 0 items received
Jul 14 15:09:39 ose3-master.example.com origin-master[990]: I0714 15:09:39.037803     990 reflector.go:294] pkg/project/controller/factory.go:37: next resync planned for time.Time{sec:63604105781, nsec:25012775, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:05 ose3-master.example.com origin-master[990]: I0714 15:10:05.875507     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.DaemonSet total 0 items received
Jul 14 15:10:05 ose3-master.example.com origin-master[990]: I0714 15:10:05.875586     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105807, nsec:857722297, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:05 ose3-master.example.com origin-master[990]: I0714 15:10:05.875507     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.Job total 0 items received
Jul 14 15:10:05 ose3-master.example.com origin-master[990]: I0714 15:10:05.875764     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105807, nsec:857809893, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:05 ose3-master.example.com origin-master[990]: I0714 15:10:05.879226     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *api.ReplicationController total 0 items received
Jul 14 15:10:05 ose3-master.example.com origin-master[990]: I0714 15:10:05.879245     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.HorizontalPodAutoscaler total 0 items received
Jul 14 15:10:05 ose3-master.example.com origin-master[990]: I0714 15:10:05.879342     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105807, nsec:864923290, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:05 ose3-master.example.com origin-master[990]: I0714 15:10:05.879369     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105807, nsec:864783326, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:06 ose3-master.example.com origin-master[990]: I0714 15:10:06.445326     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *api.Service total 0 items received
Jul 14 15:10:06 ose3-master.example.com origin-master[990]: I0714 15:10:06.445391     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105808, nsec:437518280, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:07 ose3-master.example.com origin-master[990]: I0714 15:10:07.449859     990 endpoints_controller.go:277] Finished syncing service "default/kubernetes" endpoints. (4.808µs)
Jul 14 15:10:34 ose3-master.example.com origin-master[990]: I0714 15:10:34.888755     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.DaemonSet total 0 items received
Jul 14 15:10:34 ose3-master.example.com origin-master[990]: I0714 15:10:34.888823     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105836, nsec:876515335, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:34 ose3-master.example.com origin-master[990]: I0714 15:10:34.890000     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.Job total 0 items received
Jul 14 15:10:34 ose3-master.example.com origin-master[990]: I0714 15:10:34.890044     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105836, nsec:876953053, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:34 ose3-master.example.com origin-master[990]: I0714 15:10:34.895963     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *extensions.HorizontalPodAutoscaler total 0 items received
Jul 14 15:10:34 ose3-master.example.com origin-master[990]: I0714 15:10:34.896068     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105836, nsec:883345582, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:34 ose3-master.example.com origin-master[990]: I0714 15:10:34.896501     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *api.ReplicationController total 0 items received
Jul 14 15:10:34 ose3-master.example.com origin-master[990]: I0714 15:10:34.896539     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105836, nsec:883212967, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:35 ose3-master.example.com origin-master[990]: I0714 15:10:35.452586     990 reflector.go:366] /usr/lib/golang/src/runtime/asm_amd64.s:2232: Watch close - *api.Service total 0 items received
Jul 14 15:10:35 ose3-master.example.com origin-master[990]: I0714 15:10:35.452692     990 reflector.go:294] /usr/lib/golang/src/runtime/asm_amd64.s:2232: next resync planned for time.Time{sec:63604105837, nsec:446307508, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:36 ose3-master.example.com origin-master[990]: I0714 15:10:36.457869     990 endpoints_controller.go:277] Finished syncing service "default/kubernetes" endpoints. (5.763µs)
Jul 14 15:10:36 ose3-master.example.com origin-master[990]: I0714 15:10:36.899041     990 reflector.go:366] pkg/dns/serviceaccessor.go:41: Watch close - *api.Service total 0 items received
Jul 14 15:10:36 ose3-master.example.com origin-master[990]: I0714 15:10:36.899203     990 reflector.go:294] pkg/dns/serviceaccessor.go:41: next resync planned for time.Time{sec:63604105838, nsec:894919953, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:36 ose3-master.example.com origin-master[990]: I0714 15:10:36.996987     990 reflector.go:366] pkg/project/auth/cache.go:166: Watch close - *api.Namespace total 0 items received
Jul 14 15:10:36 ose3-master.example.com origin-master[990]: I0714 15:10:36.997096     990 reflector.go:294] pkg/project/auth/cache.go:166: next resync planned for time.Time{sec:63604105838, nsec:991847328, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.046357     990 reflector.go:366] pkg/project/controller/factory.go:37: Watch close - *api.Namespace total 0 items received
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.046438     990 reflector.go:294] pkg/project/controller/factory.go:37: next resync planned for time.Time{sec:63604105840, nsec:38644126, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.961735     990 reflector.go:366] pkg/build/controller/factory/factory.go:186: Watch close - *api.Build total 0 items received
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.961884     990 reflector.go:294] pkg/build/controller/factory/factory.go:186: next resync planned for time.Time{sec:63604105840, nsec:923725487, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.976674     990 reflector.go:366] pkg/build/controller/factory/factory.go:282: Watch close - *api.BuildConfig total 0 items received
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.976763     990 reflector.go:294] pkg/build/controller/factory/factory.go:282: next resync planned for time.Time{sec:63604105840, nsec:924183630, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.976821     990 reflector.go:366] pkg/build/controller/factory/factory.go:317: Watch close - *api.BuildConfig total 0 items received
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.976860     990 reflector.go:294] pkg/build/controller/factory/factory.go:317: next resync planned for time.Time{sec:63604105840, nsec:924024248, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.984968     990 reflector.go:366] pkg/build/controller/factory/factory.go:74: Watch close - *api.Build total 0 items received
Jul 14 15:10:38 ose3-master.example.com origin-master[990]: I0714 15:10:38.985023     990 reflector.go:294] pkg/build/controller/factory/factory.go:74: next resync planned for time.Time{sec:63604105840, nsec:922721404, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.016267     990 reflector.go:366] pkg/deploy/controller/deployment/factory.go:50: Watch close - *api.ReplicationController total 0 items received
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.016376     990 reflector.go:294] pkg/deploy/controller/deployment/factory.go:50: next resync planned for time.Time{sec:63604105840, nsec:989347393, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.030967     990 reflector.go:366] pkg/deploy/controller/deployerpod/factory.go:43: Watch close - *api.ReplicationController total 0 items received
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.031046     990 reflector.go:294] pkg/deploy/controller/deployerpod/factory.go:43: next resync planned for time.Time{sec:63604105840, nsec:989660664, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.037352     990 reflector.go:366] pkg/deploy/controller/imagechange/factory.go:48: Watch close - *api.DeploymentConfig total 0 items received
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.037468     990 reflector.go:294] pkg/deploy/controller/imagechange/factory.go:48: next resync planned for time.Time{sec:63604105841, nsec:24635669, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.038815     990 reflector.go:366] pkg/deploy/controller/deploymentconfig/factory.go:43: Watch close - *api.DeploymentConfig total 0 items received
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.038880     990 reflector.go:294] pkg/deploy/controller/deploymentconfig/factory.go:43: next resync planned for time.Time{sec:63604105841, nsec:16467725, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.040203     990 reflector.go:366] pkg/deploy/controller/configchange/factory.go:43: Watch close - *api.DeploymentConfig total 0 items received
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.040358     990 reflector.go:294] pkg/deploy/controller/configchange/factory.go:43: next resync planned for time.Time{sec:63604105841, nsec:16740731, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.096147     990 reflector.go:366] pkg/build/controller/factory/factory.go:279: Watch close - *api.ImageStream total 0 items received
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.096195     990 reflector.go:294] pkg/build/controller/factory/factory.go:279: next resync planned for time.Time{sec:63604105840, nsec:924112326, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.156271     990 reflector.go:366] pkg/deploy/controller/imagechange/factory.go:37: Watch close - *api.ImageStream total 0 items received
Jul 14 15:10:39 ose3-master.example.com origin-master[990]: I0714 15:10:39.156349     990 reflector.go:294] pkg/deploy/controller/imagechange/factory.go:37: next resync planned for time.Time{sec:63604105841, nsec:24437738, loc:(*time.Location)(0x593ce40)}, forcing now
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.243291     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245727     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245791     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245820     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245847     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245873     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245899     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245924     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245949     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.245974     990 image_change_controller.go:47] Build image change controller detected ImageStream change
Jul 14 15:10:40 ose3-master.example.com origin-master[990]: I0714 15:10:40.246000     990 image_change_controller.go:47] Build image change

Is the error here at master?

990 net.go:105] Got error &net.OpError{Op:"dial", Net:"tcp", Addr:(*net.TCPAddr)(0xc20cc620c0), Err:0x6f}, trying again: "0.0.0.0:8053"
detiber commented 8 years ago

Is the error here at master?

990 net.go:105] Got error &net.OpError{Op:"dial", Net:"tcp", Addr:(*net.TCPAddr)(0xc20cc620c0), Err:0x6f}, trying again: "0.0.0.0:8053"

@anhnguyenbk no that is an expected message. SkyDNS listens on 8053 and a combination of dnsmasq and the internal service provide access to it over port 53.

I was expecting to see an error in the master log that would indicate some issue with creating the node properly, but I'm not seeing anything.

To gather a bit more information, could you also provide the output of oc describe nodes from the master host?

In the past we've had issues where a node is created, but the associated SDN subnet is not. You can try to delete the node object and see if that corrects the problem. From the master:

oc delete nodes --all
anhnguyenbk commented 8 years ago

@detiber I have found a error at begin of node log.

-- Logs begin at T5 2016-07-14 15:07:11 UTC, end at T5 2016-07-14 15:15:47 UTC. --
Th07 14 15:08:20 ose3-node1.example.com systemd[1]: Starting Origin Node...
Th07 14 15:08:26 ose3-node1.example.com origin-node[2353]: I0714 15:08:26.942552    2353 plugins.go:71] No cloud provider specified.
Th07 14 15:08:26 ose3-node1.example.com origin-node[2353]: I0714 15:08:26.943655    2353 common.go:79] Skipping loopback/non-IPv4 addr: "127.0.0.1" for node ose3-node1.example.com
Th07 14 15:08:26 ose3-node1.example.com origin-node[2353]: I0714 15:08:26.943685    2353 common.go:77] Initializing single-tenant plugin for ose3-node1.example.com (192.168.56.120)
Th07 14 15:08:26 ose3-node1.example.com origin-node[2353]: I0714 15:08:26.943716    2353 start_node.go:288] Starting node ose3-node1.example.com (v1.2.0)
Th07 14 15:08:26 ose3-node1.example.com origin-node[2353]: I0714 15:08:26.946803    2353 start_node.go:297] Connecting to API server https://ose3-master.example.com:8443
Th07 14 15:08:26 ose3-node1.example.com origin-node[2353]: I0714 15:08:26.973785    2353 node.go:131] Connecting to Docker at unix:///var/run/docker.sock
Th07 14 15:08:28 ose3-node1.example.com origin-node[2353]: I0714 15:08:28.523301    2353 manager.go:132] cAdvisor running in container: "/"
Th07 14 15:08:28 ose3-node1.example.com origin-node[2353]: E0714 15:08:28.523491    2353 common.go:192] Failed to obtain ClusterNetwork: Get https://ose3-master.example.com:8443/oapi/v1/clusternetworks/default: dial tcp 192.168.56.110:8443: connection refused
Th07 14 15:08:28 ose3-node1.example.com origin-node[2353]: F0714 15:08:28.523533    2353 node.go:310] error: SDN node startup failed: Get https://ose3-master.example.com:8443/oapi/v1/clusternetworks/default: dial tcp 192.168.56.110:8443: connection refused
Th07 14 15:08:28 ose3-node1.example.com systemd[1]: origin-node.service: main process exited, code=exited, status=255/n/a
Th07 14 15:08:28 ose3-node1.example.com systemd[1]: Failed to start Origin Node.
Th07 14 15:08:28 ose3-node1.example.com systemd[1]: Unit origin-node.service entered failed state.
Th07 14 15:08:28 ose3-node1.example.com systemd[1]: origin-node.service failed.
Th07 14 15:08:33 ose3-node1.example.com systemd[1]: origin-node.service holdoff time over, scheduling restart.
Th07 14 15:08:33 ose3-node1.example.com systemd[1]: Starting Origin Node...
2353 common.go:192] Failed to obtain ClusterNetwork: Get https://ose3-master.example.com:8443/oapi/v1/clusternetworks/default: dial tcp 192.168.56.110:8443: connection refused

curl -X GET -k https://ose3-master.example.com:8443/oapi/v1/clusternetworks/default

{
  "kind": "Status",
  "apiVersion": "v1",
  "metadata": {},
  "status": "Failure",
  "message": "User \"system:anonymous\" cannot get clusternetworks at the cluster scope",
  "reason": "Forbidden",
  "details": {
    "name": "default",
    "kind": "clusternetworks"
  },
  "code": 403
}

Why that happned?

detiber commented 8 years ago

@anhnguyenbk That error makes me think that there is an issue with the node being able to talk back to the master for some reason.

The curl output is what I would expect, since that endpoint requires authentication.

Did you run the curl command from your master or from the node? The error message indicates that the node isn't able to reach the master.

One other thing I notice is that your master is not listed under the [nodes] group in your inventory file, this shouldn't affect installation, but we currently require that the master also be a node so that it is a member of the SDN.

anhnguyenbk commented 8 years ago

@detiber I run the curl command from the node. I remove all origin, docker , etcd package and run again with master also is a node but still that error. I don't set up DNS, just write in /etc/hosts on master vm and node vm. Does it's a cause? /etc/hosts file on master vm.

127.0.0.1   ose3-master.example.com ose3-master localhost localhost.localdomain localhost4 localhost4.localdomain4
::1         localhost localhost.localdomain localhost6 localhost6.localdomain6
192.168.56.120  ose3-node1.example.com
192.168.56.110  ose3-master.example.com

/etc/hosts file on node vm.

127.0.0.1   ose3-node1.example.com ose3-node1 localhost localhost.localdomain localhost4 localhost4.localdomain4
::1         localhost localhost.localdomain localhost6 localhost6.localdomain6
192.168.56.120  ose3-node1.example.com
192.168.56.110  ose3-master.example.com

The full log of origin master. I coundn't find anything.

-- Logs begin at T7 2016-07-16 01:34:32 UTC, end at T7 2016-07-16 02:29:46 UTC. --
Th07 16 01:35:06 ose3-master.example.com systemd[1]: Starting Origin Master Service...
Th07 16 01:35:27 ose3-master.example.com origin-master[982]: W0716 01:35:27.858600     982 start_master.go:270] assetConfig.loggingPublicURL: Invalid value: "": required to view aggregated container logs in the console
Th07 16 01:35:27 ose3-master.example.com origin-master[982]: W0716 01:35:27.860100     982 start_master.go:270] assetConfig.metricsPublicURL: Invalid value: "": required to view cluster metrics in the console
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.126125     982 plugins.go:71] No cloud provider specified.
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.339066     982 genericapiserver.go:81] Adding storage destination for group
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.339158     982 genericapiserver.go:81] Adding storage destination for group extensions
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.339207     982 start_master.go:383] Starting master on 0.0.0.0:8443 (v1.2.0)
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.339219     982 start_master.go:384] Public master address is https://ose3-master.example.com:8443
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.339239     982 start_master.go:388] Using images from "openshift/origin-<component>:v1.2.0"
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.525624     982 server.go:64] etcd: peerTLS: cert = /etc/origin/master/etcd.server.crt, key = /etc/origin/master/etcd.server.key, ca = /etc/origin/master/ca.crt, trusted-ca = , client-cert-auth = false
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.713057     982 server.go:75] etcd: listening for peers on https://0.0.0.0:7001
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.713186     982 server.go:86] etcd: clientTLS: cert = /etc/origin/master/etcd.server.crt, key = /etc/origin/master/etcd.server.key, ca = /etc/origin/master/ca.crt, trusted-ca = , client-cert-auth = false
Th07 16 01:35:29 ose3-master.example.com origin-master[982]: I0716 01:35:29.897259     982 server.go:100] etcd: listening for client requests on https://0.0.0.0:4001
Th07 16 01:35:31 ose3-master.example.com origin-master[982]: I0716 01:35:31.118029     982 run.go:61] Started etcd at ose3-master.example.com:4001
Th07 16 01:35:31 ose3-master.example.com origin-master[982]: I0716 01:35:31.350449     982 run_components.go:204] Using default project node label selector:
Th07 16 01:35:32 ose3-master.example.com origin-master[982]: W0716 01:35:32.855066     982 controller.go:297] Resetting endpoints for master service "kubernetes" to &{{ } {kubernetes  default  d613389c-49c1-11e6-b29d-525400bd971e 8 0 2016-07-14 12:52:35 +0000 UTC <nil> <nil> map[] map[]} [{[{10.0.2.15 <nil>}] [] [{https 8443 TCP} {dns 8053 UDP} {dns-tcp 8053 TCP}]}]}
Th07 16 01:35:33 ose3-master.example.com origin-master[982]: I0716 01:35:33.196626     982 master.go:262] Started Kubernetes API at 0.0.0.0:8443/api/v1
Th07 16 01:35:33 ose3-master.example.com origin-master[982]: I0716 01:35:33.196750     982 master.go:262] Started Kubernetes API Extensions at 0.0.0.0:8443/apis/extensions/v1beta1
Th07 16 01:35:33 ose3-master.example.com origin-master[982]: I0716 01:35:33.196772     982 master.go:262] Started Origin API at 0.0.0.0:8443/oapi/v1
Th07 16 01:35:33 ose3-master.example.com origin-master[982]: I0716 01:35:33.196786     982 master.go:262] Started OAuth2 API at 0.0.0.0:8443/oauth
Th07 16 01:35:33 ose3-master.example.com origin-master[982]: I0716 01:35:33.196799     982 master.go:262] Started Web Console 0.0.0.0:8443/console/
Th07 16 01:35:33 ose3-master.example.com origin-master[982]: I0716 01:35:33.196811     982 master.go:262] Started Swagger Schema API at 0.0.0.0:8443/swaggerapi/
Th07 16 01:35:33 ose3-master.example.com origin-master[982]: I0716 01:35:33.998081     982 ensure.go:226] Ignoring bootstrap policy file because cluster policy found
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: I0716 01:35:34.304937     982 ensure.go:86] Added build-controller service accounts to the system:build-controller cluster role: <nil>
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: I0716 01:35:34.552093     982 ensure.go:86] Added daemonset-controller service accounts to the system:daemonset-controller cluster role: <nil>
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: I0716 01:35:34.862392     982 trace.go:57] Trace "Update /oapi/v1/clusterrolebindings/system:deployment-controller" (started 2016-07-16 01:35:34.59114628 +0000 UTC):
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: [22.274µs] [22.274µs] About to convert to expected version
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: [229.56µs] [207.286µs] Conversion done
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: [245.432µs] [15.872µs] About to store object in database
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: [270.73987ms] [270.494438ms] Object stored in database
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: [270.756195ms] [16.325µs] Self-link added
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: [271.095301ms] [339.106µs] END
Th07 16 01:35:34 ose3-master.example.com origin-master[982]: I0716 01:35:34.867074     982 ensure.go:86] Added deployment-controller service accounts to the system:deployment-controller cluster role: <nil>
Th07 16 01:35:35 ose3-master.example.com origin-master[982]: I0716 01:35:35.099592     982 ensure.go:86] Added gc-controller service accounts to the system:gc-controller cluster role: <nil>
Th07 16 01:35:35 ose3-master.example.com origin-master[982]: I0716 01:35:35.366613     982 ensure.go:86] Added hpa-controller service accounts to the system:hpa-controller cluster role: <nil>
Th07 16 01:35:35 ose3-master.example.com origin-master[982]: I0716 01:35:35.600168     982 ensure.go:86] Added job-controller service accounts to the system:job-controller cluster role: <nil>
Th07 16 01:35:35 ose3-master.example.com origin-master[982]: I0716 01:35:35.840459     982 ensure.go:86] Added namespace-controller service accounts to the system:namespace-controller cluster role: <nil>
Th07 16 01:35:36 ose3-master.example.com origin-master[982]: I0716 01:35:36.095001     982 ensure.go:86] Added pv-binder-controller service accounts to the system:pv-binder-controller cluster role: <nil>
Th07 16 01:35:36 ose3-master.example.com origin-master[982]: I0716 01:35:36.359185     982 ensure.go:86] Added pv-provisioner-controller service accounts to the system:pv-provisioner-controller cluster role: <nil>
Th07 16 01:35:36 ose3-master.example.com origin-master[982]: I0716 01:35:36.618168     982 ensure.go:86] Added pv-recycler-controller service accounts to the system:pv-recycler-controller cluster role: <nil>
Th07 16 01:35:36 ose3-master.example.com origin-master[982]: I0716 01:35:36.864343     982 ensure.go:86] Added replication-controller service accounts to the system:replication-controller cluster role: <nil>
Th07 16 01:35:36 ose3-master.example.com origin-master[982]: W0716 01:35:36.867034     982 run_components.go:179] Binding DNS on port 8053 instead of 53 (you may need to run as root and update your config), using 0.0.0.0:8053 which will not resolve from all locations
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.170289     982 run_components.go:199] DNS listening at 0.0.0.0:8053
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.174370     982 start_master.go:527] Controllers starting (*)
Th07 16 01:35:37 ose3-master.example.com systemd[1]: Started Origin Master Service.
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.782222     982 nodecontroller.go:143] Sending events to api server.
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846195     982 factory.go:155] Creating scheduler from configuration: {{ } [{MatchNodeSelector <nil>} {PodFitsResources <nil>} {PodFitsPorts <nil>} {NoDiskConflict <nil>} {Region 0xc209c3dd80}] [{LeastRequestedPriority 1 <nil>} {SelectorSpreadPriority 1 <nil>} {Zone 2 0xc209c421a0}] []}
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846285     982 factory.go:164] Registering predicate: MatchNodeSelector
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846306     982 plugins.go:122] Predicate type MatchNodeSelector already registered, reusing.
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846333     982 factory.go:164] Registering predicate: PodFitsResources
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846343     982 plugins.go:122] Predicate type PodFitsResources already registered, reusing.
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846357     982 factory.go:164] Registering predicate: PodFitsPorts
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846365     982 plugins.go:122] Predicate type PodFitsPorts already registered, reusing.
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846378     982 factory.go:164] Registering predicate: NoDiskConflict
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846387     982 plugins.go:122] Predicate type NoDiskConflict already registered, reusing.
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846399     982 factory.go:164] Registering predicate: Region
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846410     982 factory.go:170] Registering priority: LeastRequestedPriority
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846419     982 plugins.go:191] Priority type LeastRequestedPriority already registered, reusing.
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846433     982 factory.go:170] Registering priority: SelectorSpreadPriority
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846441     982 plugins.go:191] Priority type SelectorSpreadPriority already registered, reusing.
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846455     982 factory.go:170] Registering priority: Zone
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.846466     982 factory.go:190] creating scheduler with fit predicates 'map[PodFitsResources:{} PodFitsPorts:{} NoDiskConflict:{} Region:{} MatchNodeSelector:{}]' and priority functions 'map[LeastRequestedPriority:{} SelectorSpreadPriority:{} Zone:{}]
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.849341     982 replication_controller.go:208] Starting RC Manager
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.851496     982 horizontal.go:120] Starting HPA Controller
Th07 16 01:35:37 ose3-master.example.com origin-master[982]: I0716 01:35:37.852631     982 controller.go:211] Starting Daemon Sets controller manager
Th07 16 01:35:38 ose3-master.example.com origin-master[982]: I0716 01:35:38.838476     982 plugins.go:291] Loaded volume plugin "kubernetes.io/host-path"
Th07 16 01:35:38 ose3-master.example.com origin-master[982]: I0716 01:35:38.838582     982 plugins.go:291] Loaded volume plugin "kubernetes.io/nfs"
Th07 16 01:35:38 ose3-master.example.com origin-master[982]: I0716 01:35:38.838606     982 plugins.go:291] Loaded volume plugin "kubernetes.io/aws-ebs"
Th07 16 01:35:38 ose3-master.example.com origin-master[982]: I0716 01:35:38.838628     982 plugins.go:291] Loaded volume plugin "kubernetes.io/gce-pd"
Th07 16 01:35:38 ose3-master.example.com origin-master[982]: I0716 01:35:38.839209     982 plugins.go:291] Loaded volume plugin "kubernetes.io/cinder"
Th07 16 01:35:38 ose3-master.example.com origin-master[982]: I0716 01:35:38.839267     982 start_master.go:616] Started Kubernetes Controllers
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: I0716 01:35:38.995500     982 common.go:77] Initializing single-tenant plugin for ose3-master.example.com (192.168.56.110)
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: I0716 01:35:39.225643     982 start_master.go:637] Started Origin Controllers
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: I0716 01:35:39.229280     982 trace.go:57] Trace "decodeNodeList *[]api.ImageStream" (started 2016-07-16 01:35:38.360848649 +0000 UTC):
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [868.396773ms] [868.396773ms] Decoded 11 nodes
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [868.397932ms] [1.159µs] END
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: I0716 01:35:39.229329     982 trace.go:57] Trace "decodeNodeList *[]api.ImageStream" (started 2016-07-16 01:35:38.36084479 +0000 UTC):
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [3.115µs] [3.115µs] Decoding dir /openshift.io/imagestreams/openshift START
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [868.459362ms] [868.456247ms] Decoding dir /openshift.io/imagestreams/openshift END
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [868.461501ms] [2.139µs] Decoded 1 nodes
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [868.462243ms] [742ns] END
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: I0716 01:35:39.229370     982 trace.go:57] Trace "List *api.ImageStreamList" (started 2016-07-16 01:35:37.845382521 +0000 UTC):
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [6.23µs] [6.23µs] About to list etcd node
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [515.460004ms] [515.453774ms] Etcd node listed
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [1.383954721s] [868.494717ms] Node list decoded
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [1.383965887s] [11.166µs] END
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: I0716 01:35:39.232990     982 trace.go:57] Trace "List /oapi/v1/imagestreams" (started 2016-07-16 01:35:37.845320593 +0000 UTC):
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [55.694µs] [55.694µs] About to List from storage
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [1.384059185s] [1.384003491s] Listing from storage done
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [1.384145191s] [86.006µs] Self-linking done
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [1.387627821s] [3.48263ms] Writing http response done (11 items)
Th07 16 01:35:39 ose3-master.example.com origin-master[982]: [1.387629652s] [1.831µs] END
Th07 16 01:42:33 ose3-master.example.com systemd[1]: Stopping Origin Master Service...
Th07 16 01:42:33 ose3-master.example.com systemd[1]: Stopped Origin Master Service.
Th07 16 01:59:14 ose3-master.example.com systemd[1]: Starting Origin Master Service...
Th07 16 01:59:14 ose3-master.example.com origin-master[7219]: W0716 01:59:14.542176    7219 start_master.go:270] assetConfig.loggingPublicURL: Invalid value: "": required to view aggregated container logs in the console
Th07 16 01:59:14 ose3-master.example.com origin-master[7219]: W0716 01:59:14.542405    7219 start_master.go:270] assetConfig.metricsPublicURL: Invalid value: "": required to view cluster metrics in the console
Th07 16 01:59:15 ose3-master.example.com origin-master[7219]: I0716 01:59:15.476349    7219 plugins.go:71] No cloud provider specified.
Th07 16 01:59:15 ose3-master.example.com origin-master[7219]: I0716 01:59:15.683526    7219 genericapiserver.go:81] Adding storage destination for group
Th07 16 01:59:15 ose3-master.example.com origin-master[7219]: I0716 01:59:15.683667    7219 genericapiserver.go:81] Adding storage destination for group extensions
Th07 16 01:59:15 ose3-master.example.com origin-master[7219]: I0716 01:59:15.683728    7219 start_master.go:383] Starting master on 0.0.0.0:8443 (v1.2.0)
Th07 16 01:59:15 ose3-master.example.com origin-master[7219]: I0716 01:59:15.683744    7219 start_master.go:384] Public master address is https://ose3-master.example.com:8443
Th07 16 01:59:15 ose3-master.example.com origin-master[7219]: I0716 01:59:15.683770    7219 start_master.go:388] Using images from "openshift/origin-<component>:v1.2.0"
Th07 16 01:59:15 ose3-master.example.com origin-master[7219]: I0716 01:59:15.874796    7219 server.go:64] etcd: peerTLS: cert = /etc/origin/master/etcd.server.crt, key = /etc/origin/master/etcd.server.key, ca = /etc/origin/master/ca.crt, trusted-ca = , client-cert-auth = false
Th07 16 01:59:16 ose3-master.example.com origin-master[7219]: I0716 01:59:16.101280    7219 server.go:75] etcd: listening for peers on https://0.0.0.0:7001
Th07 16 01:59:16 ose3-master.example.com origin-master[7219]: I0716 01:59:16.101363    7219 server.go:86] etcd: clientTLS: cert = /etc/origin/master/etcd.server.crt, key = /etc/origin/master/etcd.server.key, ca = /etc/origin/master/ca.crt, trusted-ca = , client-cert-auth = false
Th07 16 01:59:16 ose3-master.example.com origin-master[7219]: I0716 01:59:16.311889    7219 server.go:100] etcd: listening for client requests on https://0.0.0.0:4001
Th07 16 01:59:16 ose3-master.example.com origin-master[7219]: I0716 01:59:16.741767    7219 run.go:61] Started etcd at ose3-master.example.com:4001
Th07 16 01:59:16 ose3-master.example.com origin-master[7219]: I0716 01:59:16.929974    7219 run_components.go:204] Using default project node label selector:
Th07 16 01:59:18 ose3-master.example.com origin-master[7219]: W0716 01:59:18.077691    7219 controller.go:297] Resetting endpoints for master service "kubernetes" to &{{ } {kubernetes  default  d613389c-49c1-11e6-b29d-525400bd971e 8 0 2016-07-14 12:52:35 +0000 UTC <nil> <nil> map[] map[]} [{[{10.0.2.15 <nil>}] [] [{https 8443 TCP} {dns 8053 UDP} {dns-tcp 8053 TCP}]}]}
Th07 16 01:59:18 ose3-master.example.com origin-master[7219]: I0716 01:59:18.406924    7219 master.go:262] Started Kubernetes API at 0.0.0.0:8443/api/v1
Th07 16 01:59:18 ose3-master.example.com origin-master[7219]: I0716 01:59:18.406985    7219 master.go:262] Started Kubernetes API Extensions at 0.0.0.0:8443/apis/extensions/v1beta1
Th07 16 01:59:18 ose3-master.example.com origin-master[7219]: I0716 01:59:18.407003    7219 master.go:262] Started Origin API at 0.0.0.0:8443/oapi/v1
Th07 16 01:59:18 ose3-master.example.com origin-master[7219]: I0716 01:59:18.407013    7219 master.go:262] Started OAuth2 API at 0.0.0.0:8443/oauth
Th07 16 01:59:18 ose3-master.example.com origin-master[7219]: I0716 01:59:18.407020    7219 master.go:262] Started Web Console 0.0.0.0:8443/console/
Th07 16 01:59:18 ose3-master.example.com origin-master[7219]: I0716 01:59:18.407026    7219 master.go:262] Started Swagger Schema API at 0.0.0.0:8443/swaggerapi/
Th07 16 01:59:18 ose3-master.example.com origin-master[7219]: I0716 01:59:18.649241    7219 ensure.go:226] Ignoring bootstrap policy file because cluster policy found
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: I0716 01:59:19.328653    7219 ensure.go:86] Added build-controller service accounts to the system:build-controller cluster role: <nil>
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: I0716 01:59:19.592714    7219 ensure.go:86] Added daemonset-controller service accounts to the system:daemonset-controller cluster role: <nil>
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: I0716 01:59:19.912908    7219 trace.go:57] Trace "Update /oapi/v1/clusterrolebindings/system:deployment-controller" (started 2016-07-16 01:59:19.662612143 +0000 UTC):
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: [22.698µs] [22.698µs] About to convert to expected version
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: [241.712µs] [219.014µs] Conversion done
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: [255.738µs] [14.026µs] About to store object in database
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: [249.928943ms] [249.673205ms] Object stored in database
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: [249.982539ms] [53.596µs] Self-link added
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: [250.242195ms] [259.656µs] END
Th07 16 01:59:19 ose3-master.example.com origin-master[7219]: I0716 01:59:19.914280    7219 ensure.go:86] Added deployment-controller service accounts to the system:deployment-controller cluster role: <nil>
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: I0716 01:59:20.199703    7219 ensure.go:86] Added gc-controller service accounts to the system:gc-controller cluster role: <nil>
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: I0716 01:59:20.459145    7219 ensure.go:86] Added hpa-controller service accounts to the system:hpa-controller cluster role: <nil>
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: I0716 01:59:20.750472    7219 trace.go:57] Trace "Update /oapi/v1/clusterrolebindings/system:job-controller" (started 2016-07-16 01:59:20.498361643 +0000 UTC):
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: [21.039µs] [21.039µs] About to convert to expected version
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: [219.1µs] [198.061µs] Conversion done
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: [235.198µs] [16.098µs] About to store object in database
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: [251.595469ms] [251.360271ms] Object stored in database
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: [251.675682ms] [80.213µs] Self-link added
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: [252.041536ms] [365.854µs] END
Th07 16 01:59:20 ose3-master.example.com origin-master[7219]: I0716 01:59:20.752399    7219 ensure.go:86] Added job-controller service accounts to the system:job-controller cluster role: <nil>
Th07 16 01:59:21 ose3-master.example.com origin-master[7219]: I0716 01:59:21.011081    7219 ensure.go:86] Added namespace-controller service accounts to the system:namespace-controller cluster role: <nil>
Th07 16 01:59:21 ose3-master.example.com origin-master[7219]: I0716 01:59:21.294721    7219 ensure.go:86] Added pv-binder-controller service accounts to the system:pv-binder-controller cluster role: <nil>
Th07 16 01:59:21 ose3-master.example.com origin-master[7219]: I0716 01:59:21.543048    7219 ensure.go:86] Added pv-provisioner-controller service accounts to the system:pv-provisioner-controller cluster role: <nil>
Th07 16 01:59:21 ose3-master.example.com origin-master[7219]: I0716 01:59:21.831548    7219 ensure.go:86] Added pv-recycler-controller service accounts to the system:pv-recycler-controller cluster role: <nil>
Th07 16 01:59:22 ose3-master.example.com origin-master[7219]: I0716 01:59:22.074233    7219 ensure.go:86] Added replication-controller service accounts to the system:replication-controller cluster role: <nil>
Th07 16 01:59:22 ose3-master.example.com origin-master[7219]: W0716 01:59:22.076482    7219 run_components.go:179] Binding DNS on port 8053 instead of 53 (you may need to run as root and update your config), using 0.0.0.0:8053 which will not resolve from all locations
Th07 16 01:59:22 ose3-master.example.com origin-master[7219]: I0716 01:59:22.385985    7219 run_components.go:199] DNS listening at 0.0.0.0:8053
Th07 16 01:59:22 ose3-master.example.com systemd[1]: Started Origin Master Service.
Th07 16 01:59:22 ose3-master.example.com origin-master[7219]: I0716 01:59:22.388492    7219 start_master.go:527] Controllers starting (*)
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.159989    7219 nodecontroller.go:143] Sending events to api server.
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.161534    7219 factory.go:155] Creating scheduler from configuration: {{ } [{MatchNodeSelector <nil>} {PodFitsResources <nil>} {PodFitsPorts <nil>} {NoDiskConflict <nil>} {Region 0xc20d82b700}] [{LeastRequestedPriority 1 <nil>} {SelectorSpreadPriority 1 <nil>} {Zone 2 0xc20ddfe030}] []}
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.161600    7219 factory.go:164] Registering predicate: MatchNodeSelector
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162820    7219 plugins.go:122] Predicate type MatchNodeSelector already registered, reusing.
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162867    7219 factory.go:164] Registering predicate: PodFitsResources
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162878    7219 plugins.go:122] Predicate type PodFitsResources already registered, reusing.
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162892    7219 factory.go:164] Registering predicate: PodFitsPorts
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162900    7219 plugins.go:122] Predicate type PodFitsPorts already registered, reusing.
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162911    7219 factory.go:164] Registering predicate: NoDiskConflict
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162918    7219 plugins.go:122] Predicate type NoDiskConflict already registered, reusing.
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162930    7219 factory.go:164] Registering predicate: Region
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162944    7219 factory.go:170] Registering priority: LeastRequestedPriority
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162963    7219 plugins.go:191] Priority type LeastRequestedPriority already registered, reusing.
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162982    7219 factory.go:170] Registering priority: SelectorSpreadPriority
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.162991    7219 plugins.go:191] Priority type SelectorSpreadPriority already registered, reusing.
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.163004    7219 factory.go:170] Registering priority: Zone
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.163015    7219 factory.go:190] creating scheduler with fit predicates 'map[MatchNodeSelector:{} PodFitsResources:{} PodFitsPorts:{} NoDiskConflict:{} Region:{}]' and priority functions 'map[LeastRequestedPriority:{} SelectorSpreadPriority:{} Zone:{}]
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.168225    7219 replication_controller.go:208] Starting RC Manager
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.169866    7219 horizontal.go:120] Starting HPA Controller
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.170985    7219 controller.go:211] Starting Daemon Sets controller manager
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: I0716 01:59:23.851138    7219 trace.go:57] Trace "List /api/v1/nodes" (started 2016-07-16 01:59:23.339910688 +0000 UTC):
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: [8.864µs] [8.864µs] About to List from storage
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: [510.930271ms] [510.921407ms] Listing from storage done
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: [510.96137ms] [31.099µs] Self-linking done
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: [511.165058ms] [203.688µs] Writing http response done (0 items)
Th07 16 01:59:23 ose3-master.example.com origin-master[7219]: [511.166111ms] [1.053µs] END
Th07 16 01:59:24 ose3-master.example.com origin-master[7219]: I0716 01:59:24.784934    7219 plugins.go:291] Loaded volume plugin "kubernetes.io/host-path"
Th07 16 01:59:24 ose3-master.example.com origin-master[7219]: I0716 01:59:24.785070    7219 plugins.go:291] Loaded volume plugin "kubernetes.io/nfs"
Th07 16 01:59:24 ose3-master.example.com origin-master[7219]: I0716 01:59:24.785106    7219 plugins.go:291] Loaded volume plugin "kubernetes.io/aws-ebs"
Th07 16 01:59:24 ose3-master.example.com origin-master[7219]: I0716 01:59:24.785143    7219 plugins.go:291] Loaded volume plugin "kubernetes.io/gce-pd"
Th07 16 01:59:24 ose3-master.example.com origin-master[7219]: I0716 01:59:24.785183    7219 plugins.go:291] Loaded volume plugin "kubernetes.io/cinder"
Th07 16 01:59:24 ose3-master.example.com origin-master[7219]: I0716 01:59:24.785290    7219 start_master.go:616] Started Kubernetes Controllers
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: I0716 01:59:25.085080    7219 common.go:77] Initializing single-tenant plugin for ose3-master.example.com (192.168.56.110)
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: I0716 01:59:25.132409    7219 start_master.go:637] Started Origin Controllers
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: I0716 01:59:25.265792    7219 trace.go:57] Trace "decodeNodeList *[]api.ImageStream" (started 2016-07-16 01:59:23.624752473 +0000 UTC):
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [1.640991389s] [1.640991389s] Decoded 11 nodes
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [1.64099344s] [2.051µs] END
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: I0716 01:59:25.265868    7219 trace.go:57] Trace "decodeNodeList *[]api.ImageStream" (started 2016-07-16 01:59:23.624747851 +0000 UTC):
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [3.795µs] [3.795µs] Decoding dir /openshift.io/imagestreams/openshift START
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [1.641077796s] [1.641074001s] Decoding dir /openshift.io/imagestreams/openshift END
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [1.641081535s] [3.739µs] Decoded 1 nodes
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [1.641082681s] [1.146µs] END
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: I0716 01:59:25.265944    7219 trace.go:57] Trace "List *api.ImageStreamList" (started 2016-07-16 01:59:23.181272625 +0000 UTC):
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [10.015µs] [10.015µs] About to list etcd node
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [443.47253ms] [443.462515ms] Etcd node listed
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [2.084608855s] [1.641136325s] Node list decoded
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [2.084629075s] [20.22µs] END
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: I0716 01:59:25.277092    7219 trace.go:57] Trace "List /oapi/v1/imagestreams" (started 2016-07-16 01:59:23.181184497 +0000 UTC):
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [78.665µs] [78.665µs] About to List from storage
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [2.084776277s] [2.084697612s] Listing from storage done
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [2.084955903s] [179.626µs] Self-linking done
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [2.095833068s] [10.877165ms] Writing http response done (11 items)
Th07 16 01:59:25 ose3-master.example.com origin-master[7219]: [2.095835955s] [2.887µs] END
detiber commented 8 years ago

@anhnguyenbk For uninstalling, you should use the playbook mentioned here: https://docs.openshift.org/latest/install_config/install/advanced_install.html#uninstalling-advanced

I think the issue could very well be the use of a hosts file rather than having working DNS.

@sdodson could you take a look, I think the lack of DNS is causing issues with the dnsmasq config.

anhnguyenbk commented 8 years ago

@detiber I remove the master and node, used vagrant landrush plugin for define a simple DNS, run vagrant up and ansible-playbook again. It worked perfectly. Thank you very much.

sdodson commented 8 years ago

You cannot rely on /etc/hosts entries as those don't get copied into the containers, however that shouldn't produce this particular problem, it will prevent you from being able to deploy any containers though. If you don't have working dns in this environment you can specify a dnsmasq configuration file that will get deployed to all nodes including entries for all your hosts. See https://github.com/openshift/openshift-ansible/blob/master/inventory/byo/hosts.ose.example#L412-L414

An example for yours would be a file like this

address=/ose3-master.example.com/192.168.56.110
address=/ose3-node1.example.com/192.168.56.120
anhnguyenbk commented 8 years ago

@detiber @sdodson I found the reason why I got this error. I setting up a new cluster have a working BIND DNS on 192.168.56.1. It resolve all master and nodes hostname to its IP. Before ansible run, /etc/resolv.conf file on master and nodes:

search mycom.local
nameserver 192.168.56.1

During ansible running, /etc/resolv.conf has been changed to 

search mycom.local
nameserver 10.0.2.15
nameserver 192.168.56.1

And I got this error. So I removed nameserver 10.0.2.15 from /etc/resolv.conf, run ansible again and the installation finished sucessful. Unfortunately, now I can't deploy anything on the cluster, I getting a new error

Get https://172.30.0.1:443/api/v1/namespaces/default/replicationcontrollers/<replicationcontroller_name>: dial tcp 172.30.0.1:443: getsockopt: connection refused

I added nameserver 10.0.2.15 again but the deployment still failed. I thought I had something mistake. Where I was wrong?