Skip to content
This repository has been archived by the owner on Apr 4, 2023. It is now read-only.

All log messages have the prefix "ERROR: logging before flag.Parse" #73

Closed
wallrj opened this issue Oct 31, 2017 · 1 comment · Fixed by #74
Closed

All log messages have the prefix "ERROR: logging before flag.Parse" #73

wallrj opened this issue Oct 31, 2017 · 1 comment · Fixed by #74
Labels

Comments

@wallrj
Copy link
Member

wallrj commented Oct 31, 2017

E.g.

ERROR: logging before flag.Parse: I1031 09:43:01.178940       1 round_trippers.go:442] Response Headers:
ERROR: logging before flag.Parse: I1031 09:43:01.178954       1 round_trippers.go:445]     X-Content-Type-Options: nosniff
ERROR: logging before flag.Parse: I1031 09:43:01.178964       1 round_trippers.go:445]     Content-Length: 122
ERROR: logging before flag.Parse: I1031 09:43:01.179023       1 round_trippers.go:445]     Date: Tue, 31 Oct 2017 09:43:01 GMT
ERROR: logging before flag.Parse: I1031 09:43:01.179034       1 round_trippers.go:445]     Content-Type: text/plain
ERROR: logging before flag.Parse: I1031 09:43:01.179332       1 request.go:836] Response Body: User "system:serviceaccount:navigator:navigator-navigator-controller" cannot get endpoints in the namespace "kube-system".

/kind bug

Others have had the same problem:

Solution seems to be either to pin glog to a version prior to the introduction of the check:

Or to call goflag.CommandLine.Parse([]string{})....somewhere:

@wallrj wallrj changed the title All log messages container the prefix "ERROR: logging before flag.Parse" All log messages have the prefix "ERROR: logging before flag.Parse" Oct 31, 2017
@munnerz
Copy link
Contributor

munnerz commented Oct 31, 2017

Yep, there's another example of the fix for this in cert-manager. https://github.com/jetstack-experimental/cert-manager/blob/master/cmd/controller/main.go#L35

jetstack-bot added a commit that referenced this issue Oct 31, 2017
Automatic merge from submit-queue.

Fix glog parse error in apiserver and controller logs

A hack to prevent glog prefixing every message with `ERROR: logging before flag.Parse`

The logs now look like:

```
cat apiserver.log
I1031 14:26:20.233059       1 serving.go:283] Generated self-signed cert (apiserver.local.config/certificates/apiserver.crt, apiserver.local.config/certificates/apiserver.key)
I1031 14:26:20.902689       1 serve.go:85] Serving securely on 0.0.0.0:443
```

And

```
head controller.log 
I1031 14:26:19.580479       1 controller.go:102] Creating event broadcaster
I1031 14:26:19.581139       1 leaderelection.go:174] attempting to acquire leader lease...
I1031 14:26:19.581222       1 round_trippers.go:417] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: navigator-controller/v1.8.2 (linux/amd64) kubernetes/$Format/leader-election" -H "Authorization: Bearer eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJrdWJlcm5ldGVzL3NlcnZpY2VhY2NvdW50Iiwia3ViZXJuZXRlcy5pby9zZXJ2aWNlYWNjb3VudC9uYW1lc3BhY2UiOiJkZWZhdWx0Iiwia3ViZXJuZXRlcy5pby9zZXJ2aWNlYWNjb3VudC9zZWNyZXQubmFtZSI6Im5hdi1lMmUtbmF2aWdhdG9yLWNvbnRyb2xsZXItdG9rZW4tejk0NW0iLCJrdWJlcm5ldGVzLmlvL3NlcnZpY2VhY2NvdW50L3NlcnZpY2UtYWNjb3VudC5uYW1lIjoibmF2LWUyZS1uYXZpZ2F0b3ItY29udHJvbGxlciIsImt1YmVybmV0ZXMuaW8vc2VydmljZWFjY291bnQvc2VydmljZS1hY2NvdW50LnVpZCI6Ijc1MTAxZWVmLWJlNDctMTFlNy04ODljLTUyNTQwMGI2MDhmYSIsInN1YiI6InN5c3RlbTpzZXJ2aWNlYWNjb3VudDpkZWZhdWx0Om5hdi1lMmUtbmF2aWdhdG9yLWNvbnRyb2xsZXIifQ.sQ1Rv_9Yfa_KFsGlD9f8td5OqsaCpBJzzYtpB67kXuJss_t9xu98mcqw4RBqpxxDFNu5vADKpOZlP4_kJlf8OOaEyn_IgdOVmeZxY7fN_nDk16aoEBNmn6D5thRZrXxkYGtBVKiuUqvGT0M6N8xcv1EnI_TBbnoXdxcmk4KNobKuYuBgLLmSu6zdDcLEvYtwNI0InvsMH36tfBNQpgULUR46uiGnMDXw0T3E-qLRuGPK723UZproTRG-HRk_HFZ4tEG5nIFAgkWXJzpynAgQ9thQp28CSue79ngzF1rByacpQEJH0R8sEHDTbK-csi3eOxGjpW44s6oMOG_ZERQQRw" https://10.0.0.1:443/api/v1/namespaces/kube-system/endpoints/navigator-controller
I1031 14:26:19.747554       1 round_trippers.go:436] GET https://10.0.0.1:443/api/v1/namespaces/kube-system/endpoints/navigator-controller 403 Forbidden in 166 milliseconds
I1031 14:26:19.747587       1 round_trippers.go:442] Response Headers:
I1031 14:26:19.747592       1 round_trippers.go:445]     Content-Type: text/plain
I1031 14:26:19.747597       1 round_trippers.go:445]     X-Content-Type-Options: nosniff
I1031 14:26:19.747600       1 round_trippers.go:445]     Content-Length: 118
I1031 14:26:19.747608       1 round_trippers.go:445]     Date: Tue, 31 Oct 2017 14:26:19 GMT
I1031 14:26:19.747633       1 request.go:836] Response Body: User "system:serviceaccount:default:nav-e2e-navigator-controller" cannot get endpoints in the namespace "kube-system".

```

The Pilot command already had this hack.

Note: Kubernetes solved this by pinning to an older version of glog which does not have this bug:
 * kubernetes/kubernetes#17162

They also discuss switching to a better logging framework which I think we should consider too.


**Release note**:
```release-note
NONE
```


Fixes: #73
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants