Add Debug Mode configuration and move detailed logs to Debug log level

- Add configuration to allow Debug mode that will show detailed logs. By default, they will not be written, but can be added for investigation. - Change log level of detailed logs from Info to Debug
cyberark · Sep 16, 2020 · 709bc19 · 709bc19
1 parent b6d2d1e
commit 709bc19
Show file tree

Hide file tree

Showing 6 changed files with 44 additions and 21 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -5,17 +5,23 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/en/1.0.0/)
 and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.html).
 
 ## [Unreleased]
+### Added
+- Users can set the `DEBUG` environment variable to run the client in debug mode and view more log messages.
+  [cyberark/conjur-authn-k8s-client#134](https://github.com/cyberark/conjur-authn-k8s-client/issues/134)
+
 ### Changed
+- Detailed logs moved from Info to Debug log level.
+  [cyberark/conjur-authn-k8s-client#134](https://github.com/cyberark/conjur-authn-k8s-client/issues/134)
 - Log messages now show microseconds, for clarity and easier troubleshooting.
-  ([cyberark/conjur-authn-k8s-client#164](https://github.com/cyberark/conjur-authn-k8s-client/issues/164))
+  [cyberark/conjur-authn-k8s-client#164](https://github.com/cyberark/conjur-authn-k8s-client/issues/164)
 
 ## [0.18.1] - 2020-09-13
 ### Fixed
 - Logs now correctly print only the Conjur identity without the policy branch prefix.
-  ([cyberark/conjur-authn-k8s-client#126](https://github.com/cyberark/conjur-authn-k8s-client/issues/126))
+  [cyberark/conjur-authn-k8s-client#126](https://github.com/cyberark/conjur-authn-k8s-client/issues/126)
 - When authentication fails, the exponential backoff retry is correctly reset so 
   that it will continue to attempt to authenticate until backoff is exhausted.
-  ([cyberark/conjur-authn-k8s-client#158](https://github.com/cyberark/conjur-authn-k8s-client/issues/158))
+  [cyberark/conjur-authn-k8s-client#158](https://github.com/cyberark/conjur-authn-k8s-client/issues/158)
 
 ### Changed
 - Wait slightly for the client certificate file to exist after login before
@@ -33,16 +39,16 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.
 - The authenticator-client now runs as a limited user in the Docker image
   instead of as root, which is best practice and better follows the principle of
   least privilege 
-  ([cyberark/conjur-authn-k8s-client#111](https://github.com/cyberark/conjur-authn-k8s-client/pull/111))
+  [cyberark/conjur-authn-k8s-client#111](https://github.com/cyberark/conjur-authn-k8s-client/pull/111)
 
 ## [0.17.0] - 2020-04-07
 ### Added
 - Authenticator client prints its version upon startup (#93)
 
 ## [0.16.1] - 2020-02-18
 ### Fixed
-- Only publish to DockerHub / RH registry when there is a new version (#72, #74,
-  #79, #83)
+- Only publish to DockerHub / RH registry when there is a new version
+  (#72, #74, #79, #83)
 
 ### Changed
 - Clean up implementation of default CONJUR_VERSION and add unit tests (#80)

diff --git a/cmd/authenticator/main.go b/cmd/authenticator/main.go
@@ -17,6 +17,8 @@ func main() {
 
 	var err error
 
+	configureLogLevel()
+
 	config, err := authnConfig.NewFromEnv()
 	if err != nil {
 		printErrorAndExit(log.CAKC018E)
@@ -39,6 +41,7 @@ func main() {
 	err = backoff.Retry(func() error {
 		for {
 			log.Info(log.CAKC006I, authn.Config.Username)
+
 			resp, err := authn.Authenticate()
 			if err != nil {
 				return log.RecordedError(log.CAKC016E)
@@ -49,6 +52,8 @@ func main() {
 				return log.RecordedError(log.CAKC020E)
 			}
 
+			log.Info(log.CAKC001I)
+
 			if authn.Config.ContainerMode == "init" {
 				os.Exit(0)
 			}
@@ -68,6 +73,17 @@ func main() {
 	}
 }
 
+func configureLogLevel() {
+	validVal := "true"
+	val := os.Getenv("DEBUG")
+	if val == validVal {
+		log.EnableDebugMode()
+	} else if val != "" {
+		// In case "DEBUG" is configured with incorrect value
+		log.Warn(log.CAKC001W, val, validVal)
+	}
+}
+
 func printErrorAndExit(errorMessage string) {
 	log.Error(errorMessage)
 	os.Exit(1)

diff --git a/pkg/authenticator/authenticator.go b/pkg/authenticator/authenticator.go
@@ -113,7 +113,7 @@ func (auth *Authenticator) GenerateCSR(commonName string) ([]byte, error) {
 // successfully retrieved
 func (auth *Authenticator) Login() error {
 
-	log.Info(log.CAKC007I, auth.Config.Username)
+	log.Debug(log.CAKC007I, auth.Config.Username)
 
 	csrRawBytes, err := auth.GenerateCSR(auth.Config.Username.Suffix)
 
@@ -156,7 +156,7 @@ func (auth *Authenticator) Login() error {
 
 		return log.RecordedError(log.CAKC012E, err)
 	}
-	log.Info(log.CAKC015I, auth.Config.ClientCertPath)
+	log.Debug(log.CAKC015I, auth.Config.ClientCertPath)
 
 	certDERBlock, certPEMBlock := pem.Decode(certPEMBlock)
 	cert, err := x509.ParseCertificate(certDERBlock.Bytes)
@@ -168,7 +168,7 @@ func (auth *Authenticator) Login() error {
 
 	// clean up the client cert so it's only available in memory
 	os.Remove(auth.Config.ClientCertPath)
-	log.Info(log.CAKC016I)
+	log.Debug(log.CAKC016I)
 
 	return nil
 }
@@ -183,9 +183,9 @@ func (auth *Authenticator) IsCertExpired() bool {
 	certExpiresOn := auth.PublicCert.NotAfter.UTC()
 	currentDate := time.Now().UTC()
 
-	log.Info(log.CAKC008I, certExpiresOn)
-	log.Info(log.CAKC009I, currentDate)
-	log.Info(log.CAKC010I, bufferTime)
+	log.Debug(log.CAKC008I, certExpiresOn)
+	log.Debug(log.CAKC009I, currentDate)
+	log.Debug(log.CAKC010I, bufferTime)
 
 	return currentDate.Add(bufferTime).After(certExpiresOn)
 }
@@ -194,23 +194,23 @@ func (auth *Authenticator) IsCertExpired() bool {
 // the response data. Also manages state of certificates.
 func (auth *Authenticator) Authenticate() ([]byte, error) {
 	if !auth.IsLoggedIn() {
-		log.Info(log.CAKC005I)
+		log.Debug(log.CAKC005I)
 
 		if err := auth.Login(); err != nil {
 			return nil, log.RecordedError(log.CAKC015E)
 		}
 
-		log.Info(log.CAKC002I)
+		log.Debug(log.CAKC002I)
 	}
 
 	if auth.IsCertExpired() {
-		log.Info(log.CAKC004I)
+		log.Debug(log.CAKC004I)
 
 		if err := auth.Login(); err != nil {
 			return nil, err
 		}
 
-		log.Info(log.CAKC003I)
+		log.Debug(log.CAKC003I)
 	}
 
 	privDer := x509.MarshalPKCS1PrivateKey(auth.privateKey)
@@ -263,8 +263,6 @@ func (auth *Authenticator) ParseAuthenticationResponse(response []byte) error {
 		return err
 	}
 
-	log.Info(log.CAKC001I)
-
 	return nil
 }
 

diff --git a/pkg/authenticator/requests.go b/pkg/authenticator/requests.go
@@ -20,7 +20,7 @@ func LoginRequest(authnURL string, conjurVersion string, csrBytes []byte, userna
 		authenticateURL = fmt.Sprintf("%s/inject_client_cert", authnURL)
 	}
 
-	log.Info(log.CAKC011I, authenticateURL)
+	log.Debug(log.CAKC011I, authenticateURL)
 
 	req, err := http.NewRequest("POST", authenticateURL, bytes.NewBuffer(csrBytes))
 	if err != nil {
@@ -44,7 +44,7 @@ func AuthenticateRequest(authnURL string, conjurVersion string, account string,
 		authenticateURL = fmt.Sprintf("%s/%s/%s/authenticate", authnURL, account, url.QueryEscape(username))
 	}
 
-	log.Info(log.CAKC012I, authenticateURL)
+	log.Debug(log.CAKC012I, authenticateURL)
 
 	if req, err = http.NewRequest("POST", authenticateURL, nil); err != nil {
 		return nil, log.RecordedError(log.CAKC023E, err)

diff --git a/pkg/log/log_messages.go b/pkg/log/log_messages.go
@@ -47,6 +47,9 @@ const CAKC031E string = "CAKC031E Retransmission backoff exhausted"
 const CAKC032E string = "CAKC032E Username %s is invalid"
 const CAKC033E string = "CAKC033E Timed out after waiting for %d seconds for file to exist: %s"
 
+// WARNING MESSAGES
+const CAKC001W string = "CAKC001W Incorrect value '%s' provided for enabling debug mode. Allowed value: '%s'"
+
 // INFO MESSAGES
 const CAKC001I string = "CAKC001I Successfully authenticated"
 const CAKC002I string = "CAKC002I Logged in"

diff --git a/pkg/utils/file.go b/pkg/utils/file.go
@@ -32,7 +32,7 @@ func WaitForFile(
 
 	err := backoff.Retry(func() error {
 		if limitedBackOff.RetryCount() > 0 {
-			log.Info(log.CAKC017I, path)
+			log.Debug(log.CAKC017I, path)
 		}
 
 		return verifyFileExistsFunc(path)