Warn rather than raise on opportunistic auth failure.

When opportunistic_auth is enabled but an Authorization header
could not be generated opportunistically, log a warning rather
than raising an exception. (If the request results in a 401
and we fail to generate an Authorization header in that (no-
longer-opportunistic) case, an exception is still raised.)

Also, never log Authorization header values to prevent unintentional
leaking of credentials.

HISTORY.rst

@@ -1,6 +1,18 @@
 History
 =======
 
+Unreleased
+----------
+
+- When opportunistic_auth is enabled but an Authorization header
+  could not be generated opportunistically, log a warning rather
+  than raising an exception. (If the request results in a 401
+  and we fail to generate an Authorization header in that (no-
+  longer-opportunistic) case, an exception is still raised.)
+
+- Never log Authorization header values to prevent unintentional
+  leaking of credentials.
+
 1.2.3: 2021-02-08
 -----------------
 

requests_gssapi/gssapi_.py

@@ -159,8 +159,8 @@ def generate_request_header(self, response, host, is_preemptive=False):
         except gssapi.exceptions.GSSError as error:
             msg = error.gen_message()
             log.exception(
-                "generate_request_header(): {0} failed:".format(gss_stage))
-            log.exception(msg)
+                "generate_request_header(): %s failed: %s", gss_stage, msg
+            )
             raise SPNEGOExchangeError("%s failed: %s" % (gss_stage, msg))
 
     def authenticate_user(self, response, **kwargs):
@@ -174,8 +174,7 @@ def authenticate_user(self, response, **kwargs):
             # GSS Failure, return existing response
             return response
 
-        log.debug("authenticate_user(): Authorization header: {0}".format(
-            auth_header))
+        log.debug("authenticate_user(): adding Authorization header")
         response.request.headers['Authorization'] = auth_header
 
         # Consume the content so we can reuse the connection for the next
@@ -186,7 +185,7 @@ def authenticate_user(self, response, **kwargs):
         _r = response.connection.send(response.request, **kwargs)
         _r.history.append(response)
 
-        log.debug("authenticate_user(): returning {0}".format(_r))
+        log.debug("authenticate_user(): returning %s", _r)
         return _r
 
     def handle_401(self, response, **kwargs):
@@ -195,11 +194,13 @@ def handle_401(self, response, **kwargs):
         log.debug("handle_401(): Handling: 401")
         if _negotiate_value(response) is not None:
             _r = self.authenticate_user(response, **kwargs)
-            log.debug("handle_401(): returning {0}".format(_r))
+            log.debug("handle_401(): returning %s", _r)
             return _r
         else:
-            log.debug("handle_401(): GSSAPI is not supported")
-            log.debug("handle_401(): returning {0}".format(response))
+            log.debug(
+                "handle_401(): GSSAPI is not supported -> returning %s",
+                response,
+            )
             return response
 
     def handle_other(self, response):
@@ -210,7 +211,7 @@ def handle_other(self, response):
         log.debug("handle_other(): Handling: %d" % response.status_code)
 
         if self.mutual_authentication not in (REQUIRED, OPTIONAL):
-            log.debug("handle_other(): returning {0}".format(response))
+            log.debug("handle_other(): returning %s", response)
             return response
 
         is_http_error = response.status_code >= 400
@@ -226,13 +227,15 @@ def handle_other(self, response):
                     "Unable to authenticate {0}".format(response))
 
             # Authentication successful
-            log.debug("handle_other(): returning {0}".format(response))
+            log.debug("handle_other(): returning %s", response)
             return response
         elif is_http_error or self.mutual_authentication == OPTIONAL:
             if not response.ok:
                 log.error(
                     "handle_other(): Mutual authentication unavailable on"
-                    " {0} response".format(response.status_code))
+                    " %s response",
+                    response.status_code,
+                )
 
             if self.mutual_authentication == REQUIRED and \
                self.sanitize_mutual_error_response:
@@ -252,10 +255,6 @@ def authenticate_server(self, response):
 
         Returns True on success, False on failure.
         """
-
-        log.debug("authenticate_server(): Authenticate header: {0}".format(
-            _negotiate_value(response)))
-
         host = urlparse(response.url).hostname
 
         try:
@@ -306,14 +305,18 @@ def __call__(self, request):
             # by the 401 handler
             host = urlparse(request.url).hostname
 
-            auth_header = self.generate_request_header(None, host,
-                                                       is_preemptive=True)
-
-            log.debug(
-                "HTTPSPNEGOAuth: Preemptive Authorization header: {0}"
-                .format(auth_header))
-
-            request.headers['Authorization'] = auth_header
+            try:
+                auth_header = self.generate_request_header(None, host,
+                                                           is_preemptive=True)
+            except SPNEGOExchangeError as exc:
+                log.warning(
+                    "HTTPSPNEGOAuth: Opportunistic auth failed with %s ->"
+                    " sending request without adding Authorization header",
+                    exc,
+                )
+            else:
+                log.debug("HTTPSPNEGOAuth: Adding opportunistic auth header")
+                request.headers['Authorization'] = auth_header
 
         request.register_hook('response', self.handle_response)
         try: