Bug 1818026

Summary: WMCB prints log messages to stderr
Product: OpenShift Container Platform Reporter: Sebastian Soto <ssoto>
Component: Windows ContainersAssignee: sumehta
Status: CLOSED ERRATA QA Contact: gaoshang <sgao>
Severity: medium Docs Contact:
Priority: medium    
Version: 4.4CC: aos-bugs, gmarkley, rgudimet
Target Milestone: ---   
Target Release: 4.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: No Doc Update
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-08-04 18:07:21 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 Sebastian Soto 2020-03-27 13:31:31 UTC
Description of problem:
WMCB is printing log messages to stderr. This is causing issues when captured in wmco 

{"level":"info","ts":1585233315.3780313,"logger":"windows","msg":"{\"level\":\"info\",\"ts\":1585233314.5918205,\"logger\":\"wmcb\",\"msg\":\"Bootstrapping completed successfully\"}\n","err":"bootstrapper initialization failed"}

"Bootstrapping completed successfully" is the wmcb log.


Version-Release number of selected component (if applicable):


How reproducible:
Always

Steps to Reproduce:
1. Run the bootstrapper directly or through WMCO
2. Check stderr
3.

Actual results:
WMCB prints log messages to stderr

Expected results:
WMCB prints log messages to stdout

Additional info:

Comment 4 gaoshang 2020-05-10 03:21:14 UTC
This bug has been verified and passed on OCP 4.5.0-0.nightly-2020-05-09-122546.

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

windows-machine-config-operator commit: 23198397cb0394cb2405ba700265bda24712ea9a

Steps:
1, Run the bootstrapper through WMCO, WMCB no longer prints log messages to stderr

# operator-sdk run --local --watch-namespace=windows-machine-config-operator
INFO[0000] Running the operator locally in namespace windows-machine-config-operator. 
{"level":"info","ts":1589076822.0767033,"logger":"cmd","msg":"operator","version":"0.0.1"}
{"level":"info","ts":1589076822.0768056,"logger":"cmd","msg":"go","version":"go1.13.6","os":"linux","arch":"amd64"}
{"level":"info","ts":1589076822.0768113,"logger":"cmd","msg":"operator-sdk","version":"v0.17.0"}
{"level":"info","ts":1589076822.2835965,"logger":"leader","msg":"Trying to become the leader."}
{"level":"info","ts":1589076822.283635,"logger":"leader","msg":"Skipping leader election; not running in a cluster."}
{"level":"info","ts":1589076824.469475,"logger":"controller-runtime.metrics","msg":"metrics server is starting to listen","addr":"0.0.0.0:8383"}
{"level":"info","ts":1589076824.4703429,"logger":"cmd","msg":"registering Components."}
{"level":"info","ts":1589076824.4708998,"logger":"cmd","msg":"skipping CR metrics server creation; not running in a cluster."}
{"level":"info","ts":1589076824.4709117,"logger":"cmd","msg":"starting the Cmd."}
{"level":"info","ts":1589076824.4712331,"logger":"controller-runtime.manager","msg":"starting metrics server","path":"/metrics"}
{"level":"info","ts":1589076824.4712436,"logger":"controller-runtime.controller","msg":"Starting EventSource","controller":"windowsmachineconfig-controller","source":"kind source: /, Kind="}
{"level":"info","ts":1589076824.5718079,"logger":"controller-runtime.controller","msg":"Starting EventSource","controller":"windowsmachineconfig-controller","source":"kind source: /, Kind="}
{"level":"info","ts":1589076824.6721663,"logger":"controller-runtime.controller","msg":"Starting Controller","controller":"windowsmachineconfig-controller"}
{"level":"info","ts":1589076824.672239,"logger":"controller-runtime.controller","msg":"Starting workers","controller":"windowsmachineconfig-controller","worker count":1}
{"level":"info","ts":1589076907.393196,"logger":"controller_wmc","msg":"reconciling","namespace":"windows-machine-config-operator","name":"instance"}
2020/05/09 22:15:07 kubeconfig source: /root/ocp/aws/cluster/auth/kubeconfig
{"level":"info","ts":1589076907.5490732,"logger":"controller_wmc","msg":"replicas","current":0,"desired":1}
2020/05/09 22:15:09 Using existing Security Group: sg-0a3e00a307e82de8b
2020/05/09 22:18:29 External IP: 18.191.244.162
2020/05/09 22:18:29 Internal IP: 10.0.18.183
{"level":"info","ts":1589077326.1810389,"logger":"controller_wmc","msg":"Windows VM has joined the cluster as a worker node","ID":"i-0c70607503fb76aa2"}

Comment 6 errata-xmlrpc 2020-08-04 18:07:21 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.5 image release advisory), 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:2409