Credential Logging (#685)

* Basic credential logging

* Normalize log messages

* Add tests

Co-authored-by: Vikram Jayanthi <vikramjayanthi@google.com>
Co-authored-by: Brian Rutledge <brian@bhrutledge.com>

tests/test_auth.py

@@ -1,11 +1,11 @@
+import logging
+
 import pytest
 
 from twine import auth
 from twine import exceptions
 from twine import utils
 
-cred = auth.CredentialInput
-
 
 @pytest.fixture
 def config() -> utils.RepositoryConfig:
@@ -20,7 +20,7 @@ def get_password(system, user):
 
     monkeypatch.setattr(auth, "keyring", MockKeyring)
 
-    pw = auth.Resolver(config, cred("user")).password
+    pw = auth.Resolver(config, auth.CredentialInput("user")).password
     assert pw == "user@system sekure pa55word"
 
 
@@ -32,37 +32,41 @@ def get_password(system, user):
 
     monkeypatch.setattr(auth, "keyring", MockKeyring)
 
-    pw = auth.Resolver(config, cred("user")).password
+    pw = auth.Resolver(config, auth.CredentialInput("user")).password
     assert pw == "entered pw"
 
 
 def test_no_password_defers_to_prompt(monkeypatch, entered_password, config):
     config.update(password=None)
-    pw = auth.Resolver(config, cred("user")).password
+    pw = auth.Resolver(config, auth.CredentialInput("user")).password
     assert pw == "entered pw"
 
 
 def test_empty_password_bypasses_prompt(monkeypatch, entered_password, config):
     config.update(password="")
-    pw = auth.Resolver(config, cred("user")).password
+    pw = auth.Resolver(config, auth.CredentialInput("user")).password
     assert pw == ""
 
 
 def test_no_username_non_interactive_aborts(config):
     with pytest.raises(exceptions.NonInteractive):
-        auth.Private(config, cred("user")).password
+        auth.Private(config, auth.CredentialInput("user")).password
 
 
 def test_no_password_non_interactive_aborts(config):
     with pytest.raises(exceptions.NonInteractive):
-        auth.Private(config, cred("user")).password
+        auth.Private(config, auth.CredentialInput("user")).password
 
 
-def test_get_username_and_password_keyring_overrides_prompt(monkeypatch, config):
+def test_get_username_and_password_keyring_overrides_prompt(
+    monkeypatch, config, caplog
+):
+    caplog.set_level(logging.INFO, "twine")
+
     class MockKeyring:
         @staticmethod
         def get_credential(system, user):
-            return cred(
+            return auth.CredentialInput(
                 "real_user", "real_user@{system} sekure pa55word".format(**locals())
             )
 
@@ -75,10 +79,16 @@ def get_password(system, user):
 
     monkeypatch.setattr(auth, "keyring", MockKeyring)
 
-    res = auth.Resolver(config, cred())
+    res = auth.Resolver(config, auth.CredentialInput())
+
     assert res.username == "real_user"
     assert res.password == "real_user@system sekure pa55word"
 
+    assert caplog.messages == [
+        "username set from keyring",
+        "password set from keyring",
+    ]
+
 
 @pytest.fixture
 def keyring_missing_get_credentials(monkeypatch):
@@ -94,21 +104,21 @@ def entered_username(monkeypatch):
 def test_get_username_keyring_missing_get_credentials_prompts(
     entered_username, keyring_missing_get_credentials, config
 ):
-    assert auth.Resolver(config, cred()).username == "entered user"
+    assert auth.Resolver(config, auth.CredentialInput()).username == "entered user"
 
 
 def test_get_username_keyring_missing_non_interactive_aborts(
     entered_username, keyring_missing_get_credentials, config
 ):
     with pytest.raises(exceptions.NonInteractive):
-        auth.Private(config, cred()).username
+        auth.Private(config, auth.CredentialInput()).username
 
 
 def test_get_password_keyring_missing_non_interactive_aborts(
     entered_username, keyring_missing_get_credentials, config
 ):
     with pytest.raises(exceptions.NonInteractive):
-        auth.Private(config, cred("user")).password
+        auth.Private(config, auth.CredentialInput("user")).password
 
 
 @pytest.fixture
@@ -138,7 +148,7 @@ def get_credential(system, username):
 def test_get_username_runtime_error_suppressed(
     entered_username, keyring_no_backends_get_credential, recwarn, config
 ):
-    assert auth.Resolver(config, cred()).username == "entered user"
+    assert auth.Resolver(config, auth.CredentialInput()).username == "entered user"
     assert len(recwarn) == 1
     warning = recwarn.pop(UserWarning)
     assert "fail!" in str(warning)
@@ -147,7 +157,7 @@ def test_get_username_runtime_error_suppressed(
 def test_get_password_runtime_error_suppressed(
     entered_password, keyring_no_backends, recwarn, config
 ):
-    assert auth.Resolver(config, cred("user")).password == "entered pw"
+    assert auth.Resolver(config, auth.CredentialInput("user")).password == "entered pw"
     assert len(recwarn) == 1
     warning = recwarn.pop(UserWarning)
     assert "fail!" in str(warning)
@@ -162,4 +172,33 @@ def get_credential(system, username):
             return None
 
     monkeypatch.setattr(auth, "keyring", FailKeyring())
-    assert auth.Resolver(config, cred()).username == "entered user"
+    assert auth.Resolver(config, auth.CredentialInput()).username == "entered user"
+
+
+def test_logs_cli_values(caplog):
+    caplog.set_level(logging.INFO, "twine")
+
+    res = auth.Resolver(config, auth.CredentialInput("username", "password"))
+
+    assert res.username == "username"
+    assert res.password == "password"
+
+    assert caplog.messages == [
+        "username set by command options",
+        "password set by command options",
+    ]
+
+
+def test_logs_config_values(config, caplog):
+    caplog.set_level(logging.INFO, "twine")
+
+    config.update(username="username", password="password")
+    res = auth.Resolver(config, auth.CredentialInput())
+
+    assert res.username == "username"
+    assert res.password == "password"
+
+    assert caplog.messages == [
+        "username set from config file",
+        "password set from config file",
+    ]

tests/test_repository.py

@@ -11,6 +11,7 @@
 # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 # See the License for the specific language governing permissions and
 # limitations under the License.
+import logging
 from contextlib import contextmanager
 
 import pretend
@@ -338,3 +339,23 @@ def test_package_is_uploaded_incorrect_repo_url():
     repo.url = "https://bad.repo.com/legacy"
 
     assert repo.package_is_uploaded(None) is False
+
+
+@pytest.mark.parametrize(
+    "username, password, messages",
+    [
+        (None, None, ["username: <empty>", "password: <empty>"]),
+        ("", "", ["username: <empty>", "password: <empty>"]),
+        ("username", "password", ["username: username", "password: <hidden>"]),
+    ],
+)
+def test_logs_username_and_password(username, password, messages, caplog):
+    caplog.set_level(logging.INFO, "twine")
+
+    repository.Repository(
+        repository_url=utils.DEFAULT_REPOSITORY,
+        username=username,
+        password=password,
+    )
+
+    assert caplog.messages == messages

twine/auth.py

@@ -1,5 +1,6 @@
 import functools
 import getpass
+import logging
 import warnings
 from typing import Callable, Optional, Type, cast
 
@@ -8,6 +9,8 @@
 from twine import exceptions
 from twine import utils
 
+logger = logging.getLogger(__name__)
+
 
 class CredentialInput:
     def __init__(
@@ -70,12 +73,20 @@ def get_password_from_keyring(self) -> Optional[str]:
         return None
 
     def username_from_keyring_or_prompt(self) -> str:
-        return self.get_username_from_keyring() or self.prompt("username", input)
+        username = self.get_username_from_keyring()
+        if username:
+            logger.info("username set from keyring")
+            return username
+
+        return self.prompt("username", input)
 
     def password_from_keyring_or_prompt(self) -> str:
-        return self.get_password_from_keyring() or self.prompt(
-            "password", getpass.getpass
-        )
+        password = self.get_password_from_keyring()
+        if password:
+            logger.info("password set from keyring")
+            return password
+
+        return self.prompt("password", getpass.getpass)
 
     def prompt(self, what: str, how: Callable[..., str]) -> str:
         return how(f"Enter your {what}: ")

twine/repository.py

@@ -11,6 +11,7 @@
 # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 # See the License for the specific language governing permissions and
 # limitations under the License.
+import logging
 import sys
 from typing import Any, Dict, List, Optional, Set, Tuple, cast
 
@@ -33,6 +34,8 @@
 TEST_WAREHOUSE = "https://test.pypi.org/"
 WAREHOUSE_WEB = "https://pypi.org/"
 
+logger = logging.getLogger(__name__)
+
 
 class ProgressBar(tqdm.tqdm):
     def update_to(self, n: int) -> None:
@@ -61,6 +64,9 @@ def __init__(
         self.session.auth = (
             (username or "", password or "") if username or password else None
         )
+        logger.info(f"username: {username if username else '<empty>'}")
+        logger.info(f"password: <{'hidden' if password else 'empty'}>")
+
         self.session.headers["User-Agent"] = self._make_user_agent_string()
         for scheme in ("http://", "https://"):
             self.session.mount(scheme, self._make_adapter_with_retries())

twine/utils.py

@@ -232,8 +232,10 @@ def get_userpass_value(
     :rtype: unicode
     """
     if cli_value is not None:
+        logger.info(f"{key} set by command options")
         return cli_value
     elif config.get(key) is not None:
+        logger.info(f"{key} set from config file")
         return config[key]
     elif prompt_strategy:
         return prompt_strategy()