Bug 1859537

Summary: Connection timed out when WMCO reconciling Windows node
Product: OpenShift Container Platform Reporter: gaoshang <sgao>
Component: Windows ContainersAssignee: Aravindh Puthiyaparambil <aravindh>
Status: CLOSED ERRATA QA Contact: gaoshang <sgao>
Severity: high Docs Contact:
Priority: high    
Version: 4.6CC: aos-bugs, aravindh, gmarkley, rgudimet
Target Milestone: ---   
Target Release: 4.6.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-10-27 16:16:41 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description gaoshang 2020-07-22 11:08:03 UTC
Description of problem:
Get connection timed out error when WMCO reconciling Windows node, it happens most when the first time adding a Windows node in cluster, which create a new Security Group and enable port 22 for SSH access.

Version-Release number of selected component (if applicable):
# oc get clusterversion
NAME      VERSION                             AVAILABLE   PROGRESSING   SINCE   STATUS
version   4.5.0-0.nightly-2020-07-20-152128   True        False         31h     Cluster version is 4.5.0-0.nightly-2020-07-20-152128

windows-machine-config-operator git commit: 7a1e40606fafcc8491af2902c608b1be6138246c

How reproducible:
Sometimes

Steps to Reproduce:
1. Install a fresh OCP cluster and run WMCO operator 
2. Create windowsmachineconfig instance, check WMCO log, get "connection timed out" error for the first Windows machine, after it failed, WMCO reconciled another one which succeed.

$ oc create -f deploy/crds/wmc.openshift.io_v1alpha1_windowsmachineconfig_cr.yaml

# oc logs -f deployment.apps/windows-machine-config-operator -n windows-machine-config-operator
2020-07-21T03:34:29.746Z	INFO	cmd	operator	{"version": "0.0.1"}
2020-07-21T03:34:29.747Z	INFO	cmd	go	{"version": "go1.14.4", "os": "linux", "arch": "amd64"}
2020-07-21T03:34:29.747Z	INFO	cmd	operator-sdk	{"version": "v0.18.1"}
2020-07-21T03:34:29.765Z	INFO	leader	Trying to become the leader.
2020-07-21T03:34:29.766Z	DEBUG	k8sutil	Found namespace	{"Namespace": "windows-machine-config-operator"}
I0721 03:34:30.816754       1 request.go:621] Throttling request took 1.038253468s, request: GET:https://172.30.0.1:443/apis/machine.openshift.io/v1beta1?timeout=32s
2020-07-21T03:34:31.927Z	DEBUG	k8sutil	Found podname	{"Pod.Name": "windows-machine-config-operator-57dc856bbd-89w4j"}
2020-07-21T03:34:31.947Z	DEBUG	k8sutil	Found Pod	{"Pod.Namespace": "windows-machine-config-operator", "Pod.Name": "windows-machine-config-operator-57dc856bbd-89w4j"}
2020-07-21T03:34:31.951Z	INFO	leader	No pre-existing lock was found.
2020-07-21T03:34:31.957Z	INFO	leader	Became the leader.
2020-07-21T03:34:34.116Z	INFO	controller-runtime.metrics	metrics server is starting to listen	{"addr": "0.0.0.0:8383"}
2020-07-21T03:34:34.116Z	INFO	cmd	registering Components.
2020-07-21T03:34:36.284Z	INFO	windowsmachineconfig-controller	 Skipping VM map initialization as tracker does not exist
2020-07-21T03:34:36.285Z	DEBUG	k8sutil	Found namespace	{"Namespace": "windows-machine-config-operator"}
2020-07-21T03:34:36.285Z	DEBUG	kubemetrics	Starting collecting operator types
2020-07-21T03:34:36.285Z	DEBUG	kubemetrics	Generating metric families	{"apiVersion": "machine.openshift.io/v1beta1", "kind": "Machine"}
2020-07-21T03:34:38.440Z	DEBUG	kubemetrics	Generating metric families	{"apiVersion": "wmc.openshift.io/v1alpha1", "kind": "WindowsMachineConfig"}
2020-07-21T03:34:40.594Z	DEBUG	kubemetrics	Starting serving custom resource metrics
I0721 03:34:41.644940       1 request.go:621] Throttling request took 1.044505922s, request: GET:https://172.30.0.1:443/apis/operators.coreos.com/v1?timeout=32s
2020-07-21T03:34:42.748Z	DEBUG	k8sutil	Found namespace	{"Namespace": "windows-machine-config-operator"}
2020-07-21T03:34:42.748Z	DEBUG	k8sutil	Found podname	{"Pod.Name": "windows-machine-config-operator-57dc856bbd-89w4j"}
2020-07-21T03:34:42.751Z	DEBUG	k8sutil	Found Pod	{"Pod.Namespace": "windows-machine-config-operator", "Pod.Name": "windows-machine-config-operator-57dc856bbd-89w4j"}
2020-07-21T03:34:42.761Z	DEBUG	metrics	Pods owner found	{"Kind": "Deployment", "Name": "windows-machine-config-operator", "Namespace": "windows-machine-config-operator"}
2020-07-21T03:34:42.780Z	INFO	metrics	Metrics Service object created	{"Service.Name": "windows-machine-config-operator-metrics", "Service.Namespace": "windows-machine-config-operator"}
2020-07-21T03:34:44.945Z	INFO	cmd	starting the Cmd.
2020-07-21T03:34:44.945Z	INFO	controller-runtime.manager	starting metrics server	{"path": "/metrics"}
2020-07-21T03:34:44.945Z	INFO	controller-runtime.controller	Starting EventSource	{"controller": "windowsmachineconfig-controller", "source": "kind source: /, Kind="}
2020-07-21T03:34:45.146Z	INFO	controller-runtime.controller	Starting EventSource	{"controller": "windowsmachineconfig-controller", "source": "kind source: /, Kind="}
2020-07-21T03:34:45.347Z	INFO	controller-runtime.controller	Starting Controller	{"controller": "windowsmachineconfig-controller"}
2020-07-21T03:34:45.347Z	INFO	controller-runtime.controller	Starting workers	{"controller": "windowsmachineconfig-controller", "worker count": 1}
-----------------------------------------------------------------------
2020-07-22T02:03:57.733Z	INFO	windowsmachineconfig-controller	reconciling	{"namespace": "windows-machine-config-operator", "name": "instance"}
2020/07/22 02:03:57 kubeconfig source: 
2020-07-22T02:03:57.754Z	INFO	windowsmachineconfig-controller	Creating a new Secret	{"Secret.Namespace": "openshift-machine-api", "Secret.Name": "windows-user-data"}
2020-07-22T02:03:57.768Z	INFO	windowsmachineconfig-controller	replicas	{"current": 0, "desired": 1}
2020-07-22T02:03:57.771Z	DEBUG	windowsmachineconfig-controller	updating status	{"status": {"joinedVMCount":0,"conditions":[{"type":"Reconciling","status":"True","lastTransitionTime":"2020-07-22T02:03:57Z"}]}}
2020-07-22T02:03:57.778Z	DEBUG	windowsmachineconfig-controller	creating a Windows VM
2020/07/22 02:03:59 Added rule with port 5986 to the security groups of your local IP 
2020/07/22 02:03:59 Added rule with port 22 to the security groups of your local IP 
2020/07/22 02:03:59 Added rule with port 3389 to the security groups of your local IP 
2020/07/22 02:03:59 Using existing Security Group: sg-0d999595b5940758e
2020-07-22T02:10:57.416Z	ERROR	windowsmachineconfig-controller	error adding a Windows worker node	{"error": "VMCreationFailure: error creating windows VM: failed to get ssh client for the Windows VM created: failed to dial to ssh server: dial tcp 10.0.168.249:22: connect: connection timed out"}
github.com/go-logr/zapr.(*zapLogger).Error
	/root/go/pkg/mod/github.com/go-logr/zapr.1/zapr.go:128
github.com/openshift/windows-machine-config-operator/pkg/controller/windowsmachineconfig.(*ReconcileWindowsMachineConfig).addWorkerNodes
	windows-machine-config-operator/pkg/controller/windowsmachineconfig/windowsmachineconfig_controller.go:441
github.com/openshift/windows-machine-config-operator/pkg/controller/windowsmachineconfig.(*ReconcileWindowsMachineConfig).reconcileWindowsNodes
	windows-machine-config-operator/pkg/controller/windowsmachineconfig/windowsmachineconfig_controller.go:331
github.com/openshift/windows-machine-config-operator/pkg/controller/windowsmachineconfig.(*ReconcileWindowsMachineConfig).Reconcile
	windows-machine-config-operator/pkg/controller/windowsmachineconfig/windowsmachineconfig_controller.go:292
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
	/root/go/pkg/mod/sigs.k8s.io/controller-runtime.0/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
	/root/go/pkg/mod/sigs.k8s.io/controller-runtime.0/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
	/root/go/pkg/mod/sigs.k8s.io/controller-runtime.0/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1
	/root/go/pkg/mod/k8s.io/apimachinery.2/pkg/util/wait/wait.go:155
k8s.io/apimachinery/pkg/util/wait.BackoffUntil
	/root/go/pkg/mod/k8s.io/apimachinery.2/pkg/util/wait/wait.go:156
k8s.io/apimachinery/pkg/util/wait.JitterUntil
	/root/go/pkg/mod/k8s.io/apimachinery.2/pkg/util/wait/wait.go:133
k8s.io/apimachinery/pkg/util/wait.Until
	/root/go/pkg/mod/k8s.io/apimachinery.2/pkg/util/wait/wait.go:90
2020-07-22T02:10:57.416Z	DEBUG	windowsmachineconfig-controller	starting tracker reconciliation
2020-07-22T02:10:57.435Z	DEBUG	windowsmachineconfig-controller	completed tracker reconciliation
2020-07-22T02:10:57.439Z	DEBUG	windowsmachineconfig-controller	updating status	{"status": {"joinedVMCount":0,"conditions":[{"type":"Reconciling","status":"False","lastTransitionTime":"2020-07-22T02:10:57Z"},{"type":"Degraded","status":"True","lastTransitionTime":"2020-07-22T02:10:57Z","reason":"VMCreationFailure","message":"VMCreationFailure: error creating windows VM: failed to get ssh client for the Windows VM created: failed to dial to ssh server: dial tcp 10.0.168.249:22: connect: connection timed out"}]}}
2020-07-22T02:10:57.446Z	ERROR	controller-runtime.controller	Reconciler error	{"controller": "windowsmachineconfig-controller", "request": "windows-machine-config-operator/instance", "error": "reconcile error: [VMCreationFailure: error creating windows VM: failed to get ssh client for the Windows VM created: failed to dial to ssh server: dial tcp 10.0.168.249:22: connect: connection timed out]"}
github.com/go-logr/zapr.(*zapLogger).Error
	/root/go/pkg/mod/github.com/go-logr/zapr.1/zapr.go:128
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
	/root/go/pkg/mod/sigs.k8s.io/controller-runtime.0/pkg/internal/controller/controller.go:258
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
	/root/go/pkg/mod/sigs.k8s.io/controller-runtime.0/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
	/root/go/pkg/mod/sigs.k8s.io/controller-runtime.0/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1
	/root/go/pkg/mod/k8s.io/apimachinery.2/pkg/util/wait/wait.go:155
k8s.io/apimachinery/pkg/util/wait.BackoffUntil
	/root/go/pkg/mod/k8s.io/apimachinery.2/pkg/util/wait/wait.go:156
k8s.io/apimachinery/pkg/util/wait.JitterUntil
	/root/go/pkg/mod/k8s.io/apimachinery.2/pkg/util/wait/wait.go:133
k8s.io/apimachinery/pkg/util/wait.Until
	/root/go/pkg/mod/k8s.io/apimachinery.2/pkg/util/wait/wait.go:90
2020-07-22T02:10:57.451Z	INFO	windowsmachineconfig-controller	reconciling	{"namespace": "windows-machine-config-operator", "name": "instance"}
2020/07/22 02:10:57 kubeconfig source: 
2020-07-22T02:10:57.479Z	INFO	windowsmachineconfig-controller	replicas	{"current": 0, "desired": 1}
2020-07-22T02:10:57.483Z	DEBUG	windowsmachineconfig-controller	updating status	{"status": {"joinedVMCount":0,"conditions":[{"type":"Degraded","status":"True","lastTransitionTime":"2020-07-22T02:10:57Z","reason":"VMCreationFailure","message":"VMCreationFailure: error creating windows VM: failed to get ssh client for the Windows VM created: failed to dial to ssh server: dial tcp 10.0.168.249:22: connect: connection timed out"},{"type":"Reconciling","status":"True","lastTransitionTime":"2020-07-22T02:10:57Z"}]}}
2020-07-22T02:10:57.490Z	DEBUG	windowsmachineconfig-controller	creating a Windows VM
2020/07/22 02:10:58 Using existing Security Group: sg-0d999595b5940758e
2020/07/22 02:16:50 External IP: 
2020/07/22 02:16:50 Internal IP: 10.0.175.136
2020-07-22T02:16:50.822Z	DEBUG	windowsmachineconfig-controller	configuring the Windows VM	{"ID": "i-07ab3877cd744150a"}
2020-07-22T02:17:29.154Z	DEBUG	VM i-07ab3877cd744150a	ignition file download	{"cmd": "C:\\Temp\\wget-ignore-cert.ps1 -server https://api-int.sgao.qe.devcluster.openshift.com:22623/config/worker -output C:\\Windows\\Temp\\worker.ign -useragent Ignition/0.35.0", "output": ""}
2020-07-22T02:17:33.861Z	DEBUG	VM i-07ab3877cd744150a	output from wmcb	{"output": "Bootstrapping completed successfully"}
2020-07-22T02:21:03.052Z	DEBUG	VM i-07ab3877cd744150a	started service	{"name": "kube-proxy", "binary": "C:\\k\\kube-proxy.exe", "args": "--windows-service --v=4 --proxy-mode=kernelspace --feature-gates=WinOverlay=true --hostname-override=ip-10-0-175-136.us-east-2.compute.internal --kubeconfig=c:\\k\\kubeconfig --cluster-cidr=10.132.0.0/24 --log-dir=C:\\k\\log\\kube-proxy\\ --logtostderr=false --network-name=OVNKubernetesHybridOverlayNetwork --source-vip=10.132.0.82 --enable-dsr=false"}
2020-07-22T02:21:03.052Z	INFO	windowsmachineconfig-controller	Windows VM has joined the cluster as a worker node	{"ID": "i-07ab3877cd744150a"}
2020-07-22T02:21:03.052Z	DEBUG	windowsmachineconfig-controller	starting tracker reconciliation
2020-07-22T02:21:03.078Z	DEBUG	windowsmachineconfig-controller	completed tracker reconciliation
2020-07-22T02:21:03.082Z	DEBUG	windowsmachineconfig-controller	updating status	{"status": {"joinedVMCount":1,"conditions":[{"type":"Reconciling","status":"False","lastTransitionTime":"2020-07-22T02:21:03Z"},{"type":"Degraded","status":"False","lastTransitionTime":"2020-07-22T02:21:03Z"}]}}
2020-07-22T02:21:03.089Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachineconfig-controller", "request": "windows-machine-config-operator/instance"}

Actual results:
Get connection timed out error

Expected results:
No connection timed out error

Additional info:
It was first noticed in WNI, please see https://issues.redhat.com/browse/WINC-456 for details.

Comment 1 Aravindh Puthiyaparambil 2020-07-22 14:45:10 UTC
@sgao, please test with 4.6 clusters. We don't support WMCO with 4.5. You are also using go 1.14. Please use go 1.13 to match with what we are using. 

Is https://github.com/openshift/windows-machine-config-operator/pull/77 included in your run? That PR has a fix for the scenario you are running into.

Moreover we are moving away from WNI for creating the Windows VMs and switching to MachineSets. Please see https://github.com/openshift/windows-machine-config-operator/pull/81. I suggest closing this for now and keeping an eye out if this happens once we do the switch over.

Comment 2 Aravindh Puthiyaparambil 2020-07-22 22:52:08 UTC
This definitely is an issue. Seeing it on the PR where I am disabling the kube version check: https://prow.ci.openshift.org/view/gs/origin-ci-test/pr-logs/pull/openshift_windows-machine-config-operator/83/pull-ci-openshift-windows-machine-config-operator-master-e2e-operator/1286027984758640640.

@sgao, please keep this open.

Comment 3 gaoshang 2020-07-23 10:16:19 UTC
(In reply to Aravindh Puthiyaparambil from comment #2)
> This definitely is an issue. Seeing it on the PR where I am disabling the
> kube version check:
> https://prow.ci.openshift.org/view/gs/origin-ci-test/pr-logs/pull/
> openshift_windows-machine-config-operator/83/pull-ci-openshift-windows-
> machine-config-operator-master-e2e-operator/1286027984758640640.
> 
> @sgao, please keep this open.

Sure, thanks for the info, I'll test it with 4.6 cluster + go 1.13 when fixed.

Comment 7 gaoshang 2020-07-24 11:13:13 UTC
This bug has been verified with OCP 4.6.0-0.nightly-2020-07-24-002417 by skipping clusterconfig.validate

Steps:
1. Install a fresh OCP cluster and run WMCO operator 
2. Create a Windows machineset, check WMCO log, when SSH dial connection timed out, operator will retry and finally bootstrapped.

# oc logs -f deployment.apps/windows-machine-config-operator
2020-07-24T07:37:56.520Z	INFO	cmd	operator	{"version": "0.0.1"}
2020-07-24T07:37:56.520Z	INFO	cmd	go	{"version": "go1.13.14", "os": "linux", "arch": "amd64"}
2020-07-24T07:37:56.520Z	INFO	cmd	operator-sdk	{"version": "v0.18.1"}
2020-07-24T07:37:56.529Z	INFO	leader	Trying to become the leader.
2020-07-24T07:37:56.529Z	DEBUG	k8sutil	Found namespace	{"Namespace": "windows-machine-config-operator"}
I0724 07:37:57.579949       1 request.go:621] Throttling request took 1.0457767s, request: GET:https://172.30.0.1:443/apis/cloudcredential.openshift.io/v1?timeout=32s
2020-07-24T07:37:58.682Z	DEBUG	k8sutil	Found podname	{"Pod.Name": "windows-machine-config-operator-664986f85b-sp94n"}
2020-07-24T07:37:58.692Z	DEBUG	k8sutil	Found Pod	{"Pod.Namespace": "windows-machine-config-operator", "Pod.Name": "windows-machine-config-operator-664986f85b-sp94n"}
2020-07-24T07:37:58.694Z	INFO	leader	No pre-existing lock was found.
2020-07-24T07:37:58.700Z	INFO	leader	Became the leader.
2020-07-24T07:38:00.855Z	INFO	controller-runtime.metrics	metrics server is starting to listen	{"addr": "0.0.0.0:8383"}
2020-07-24T07:38:00.856Z	INFO	cmd	registering Components.
2020-07-24T07:38:03.012Z	DEBUG	k8sutil	Found namespace	{"Namespace": "windows-machine-config-operator"}
2020-07-24T07:38:03.012Z	DEBUG	kubemetrics	Starting collecting operator types
2020-07-24T07:38:03.012Z	DEBUG	kubemetrics	Generating metric families	{"apiVersion": "machine.openshift.io/v1beta1", "kind": "Machine"}
2020-07-24T07:38:05.167Z	DEBUG	kubemetrics	Starting serving custom resource metrics
2020-07-24T07:38:07.321Z	DEBUG	k8sutil	Found namespace	{"Namespace": "windows-machine-config-operator"}
2020-07-24T07:38:07.321Z	DEBUG	k8sutil	Found podname	{"Pod.Name": "windows-machine-config-operator-664986f85b-sp94n"}
2020-07-24T07:38:07.325Z	DEBUG	k8sutil	Found Pod	{"Pod.Namespace": "windows-machine-config-operator", "Pod.Name": "windows-machine-config-operator-664986f85b-sp94n"}
2020-07-24T07:38:07.334Z	DEBUG	metrics	Pods owner found	{"Kind": "Deployment", "Name": "windows-machine-config-operator", "Namespace": "windows-machine-config-operator"}
2020-07-24T07:38:07.353Z	INFO	metrics	Metrics Service object created	{"Service.Name": "windows-machine-config-operator-metrics", "Service.Namespace": "windows-machine-config-operator"}
I0724 07:38:08.403861       1 request.go:621] Throttling request took 1.043664612s, request: GET:https://172.30.0.1:443/apis/storage.k8s.io/v1?timeout=32s
2020-07-24T07:38:09.526Z	INFO	cmd	starting the Cmd.
2020-07-24T07:38:09.526Z	INFO	controller-runtime.manager	starting metrics server	{"path": "/metrics"}
2020-07-24T07:38:09.526Z	INFO	controller-runtime.controller	Starting EventSource	{"controller": "windowsmachine-controller", "source": "kind source: /, Kind="}
2020-07-24T07:38:09.727Z	INFO	controller-runtime.controller	Starting Controller	{"controller": "windowsmachine-controller"}
2020-07-24T07:38:09.727Z	INFO	controller-runtime.controller	Starting workers	{"controller": "windowsmachine-controller", "worker count": 1}
2020-07-24T08:27:37.699Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:37.707Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:37.775Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:37.782Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:39.514Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:39.523Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:39.526Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:39.533Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:59.832Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:59.843Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:59.843Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:59.851Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:59.854Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:27:59.862Z	DEBUG	windowsmachine-controller	configuring the Windows VM	{"ID": "i-0181b2e1f467b1298"}
-----------------------------------------------------------------------

2020-07-24T08:30:11.982Z	DEBUG	VM i-0181b2e1f467b1298	SSH dial	{"IP Address": "10.0.151.105", "error": "dial tcp 10.0.151.105:22: connect: connection timed out"}
2020-07-24T08:33:20.398Z	DEBUG	VM i-0181b2e1f467b1298	SSH dial	{"IP Address": "10.0.151.105", "error": "dial tcp 10.0.151.105:22: connect: connection timed out"}
-----------------------------------------------------------------------

2020-07-24T08:34:53.685Z	DEBUG	VM i-0181b2e1f467b1298	ignition file download	{"cmd": "C:\\Temp\\wget-ignore-cert.ps1 -server https://api-int.sgao.qe.devcluster.openshift.com:22623/config/worker -output C:\\Windows\\Temp\\worker.ign -useragent Ignition/0.35.0", "output": ""}
2020-07-24T08:34:58.255Z	DEBUG	VM i-0181b2e1f467b1298	output from wmcb	{"output": "Bootstrapping completed successfully"}
2020-07-24T08:35:13.261Z	DEBUG	nodeconfig	worker label %s already present on node %s	{"node-role.kubernetes.io/worker": "ip-10-0-151-105.us-east-2.compute.internal"}
2020-07-24T08:38:08.664Z	DEBUG	VM i-0181b2e1f467b1298	started service	{"name": "kube-proxy", "binary": "C:\\k\\kube-proxy.exe", "args": "--windows-service --v=4 --proxy-mode=kernelspace --feature-gates=WinOverlay=true --hostname-override=ip-10-0-151-105.us-east-2.compute.internal --kubeconfig=c:\\k\\kubeconfig --cluster-cidr=10.132.0.0/24 --log-dir=C:\\k\\log\\kube-proxy\\ --logtostderr=false --network-name=OVNKubernetesHybridOverlayNetwork --source-vip=10.132.0.23 --enable-dsr=false"}
2020-07-24T08:38:08.664Z	INFO	windowsmachine-controller	Windows VM has joined the cluster as a worker node	{"ID": "i-0181b2e1f467b1298"}
2020-07-24T08:38:08.664Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:38:08.664Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T08:38:08.665Z	DEBUG	controller-runtime.manager.events	Normal	{"object": {"kind":"Machine","namespace":"openshift-machine-api","name":"sgao-d2wtc-windows-worker-us-east-2a-6nr8v","uid":"637fa39c-1c09-476f-a21a-e68c202fddfa","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"297231"}, "reason": "WMCO Setup", "message": "Machine sgao-d2wtc-windows-worker-us-east-2a-6nr8v Configured Successfully"}
2020-07-24T08:38:08.673Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T09:19:23.010Z	INFO	windowsmachine-controller	reconciling	{"namespace": "openshift-machine-api", "name": "sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}
2020-07-24T09:19:23.020Z	DEBUG	controller-runtime.controller	Successfully Reconciled	{"controller": "windowsmachine-controller", "request": "openshift-machine-api/sgao-d2wtc-windows-worker-us-east-2a-6nr8v"}

Comment 9 errata-xmlrpc 2020-10-27 16:16:41 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (OpenShift Container Platform 4.6 GA Images), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:4196