az devops login fails to add PAT to Mac OS keychain

[OnnoH]

This is autogenerated. Please review and update as needed.

Describe the bug

Command Name az devops login Extension Name: azure-devops. Version: 0.13.0.

Errors:

Can't store password on keychain
Traceback (most recent call last):
azure-devops/keyring/backends/OS_X.py, ln 36, in set_password
    self.keychain, service, username, password)
azure-devops/keyring/backends/_OS_X_API.py, ln 247, in set_generic_password
    NotFound.raise_for_status(status, "Unable to set password")
azure-devops/keyring/backends/_OS_X_API.py, ln 50, in raise_for_status
    Error.raise_for_status(status, msg)
azure-devops/keyring/backends/_OS_X_API.py, ln 42, in raise_for_status
    raise cls(status, msg)
keyring.backends._OS_X_API.Error: (-25308, 'Unable to set password')

...

azure-devops/keyring/backends/OS_X.py, ln 38, in set_password
    raise PasswordSetError("Can't store password on keychain")
keyring.errors.PasswordSetError: Can't store password on keychain

To Reproduce:

Steps to reproduce the behavior. Note that argument values have been redacted, as they may contain sensitive information.

• Put any pre-requisite steps here...
• az devops login

Expected Behavior

Environment Summary

Darwin-19.2.0-x86_64-i386-64bit
Python 3.7.4
Shell: bash

azure-cli 2.0.74 *

Extensions:
azure-devops 0.13.0

Additional Context

[OnnoH]

Updated the devops extension to 0.16.0 and the latest azure-cli. The output is less verbose, but the outcome the same: 'Can't store password on keychain'

[ishitam8]

HI @OnnoH ,

Can you re-run the command with --debug switch and share the logs?

Also, keychain application on your system must be asking you to configure a password when you run az devops login. Can you confirm if your keychain application is working properly?

[OnnoH]

Keychain.app is working properly, but it doesn't ask for a password when running the command.

Debug output:

Command arguments: ['devops', 'login', '--debug']
Event: Cli.PreExecute []
Event: CommandParser.OnGlobalArgumentsCreate [<function CLILogging.on_global_arguments at 0x10f6df9d0>, <function OutputProducer.on_global_arguments at 0x10f7670d0>, <function CLIQuery.on_global_arguments at 0x10f784550>]
Event: CommandInvoker.OnPreCommandTableCreate []
Installed command modules ['acr', 'acs', 'advisor', 'ams', 'apim', 'appconfig', 'appservice', 'backup', 'batch', 'batchai', 'billing', 'botservice', 'cdn', 'cloud', 'cognitiveservices', 'configure', 'consumption', 'container', 'cosmosdb', 'deploymentmanager', 'dla', 'dls', 'dms', 'eventgrid', 'eventhubs', 'extension', 'feedback', 'find', 'hdinsight', 'interactive', 'iot', 'iotcentral', 'keyvault', 'kusto', 'lab', 'managedservices', 'maps', 'monitor', 'natgateway', 'netappfiles', 'network', 'policyinsights', 'privatedns', 'profile', 'rdbms', 'redis', 'relay', 'reservations', 'resource', 'role', 'search', 'security', 'servicebus', 'servicefabric', 'signalr', 'sql', 'sqlvm', 'storage', 'vm']
Loaded module 'acr' in 0.005 seconds.
Loaded module 'acs' in 0.009 seconds.
Loaded module 'advisor' in 0.002 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'ams' in 0.006 seconds.
Loaded module 'apim' in 0.003 seconds.
Loaded module 'appconfig' in 0.005 seconds.
Loaded module 'appservice' in 0.009 seconds.
Loaded module 'backup' in 0.004 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'batch' in 0.010 seconds.
Loaded module 'batchai' in 0.004 seconds.
Loaded module 'billing' in 0.003 seconds.
Loaded module 'botservice' in 0.016 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'cdn' in 0.004 seconds.
Loaded module 'cloud' in 0.003 seconds.
Loaded module 'cognitiveservices' in 0.003 seconds.
Loaded module 'configure' in 0.002 seconds.
Loaded module 'consumption' in 0.004 seconds.
Loaded module 'container' in 0.003 seconds.
Loaded module 'cosmosdb' in 0.008 seconds.
Loaded module 'deploymentmanager' in 0.004 seconds.
Loaded module 'dla' in 0.005 seconds.
Loaded module 'dls' in 0.004 seconds.
Loaded module 'dms' in 0.003 seconds.
Loaded module 'eventgrid' in 0.004 seconds.
Loaded module 'eventhubs' in 0.004 seconds.
Loaded module 'extension' in 0.001 seconds.
Loaded module 'feedback' in 0.001 seconds.
Loaded module 'find' in 0.001 seconds.
Loaded module 'hdinsight' in 0.003 seconds.
Loaded module 'interactive' in 0.001 seconds.
Loaded module 'iot' in 0.005 seconds.
Loaded module 'iotcentral' in 0.002 seconds.
Loaded module 'keyvault' in 0.006 seconds.
Loaded module 'kusto' in 0.003 seconds.
Loaded module 'lab' in 0.004 seconds.
Loaded module 'managedservices' in 0.002 seconds.
Loaded module 'maps' in 0.002 seconds.
Loaded module 'monitor' in 0.007 seconds.
Loaded module 'natgateway' in 0.002 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'netappfiles' in 0.004 seconds.
Loaded module 'network' in 0.028 seconds.
Loaded module 'policyinsights' in 0.003 seconds.
Loaded module 'privatedns' in 0.005 seconds.
Loaded module 'profile' in 0.003 seconds.
Loaded module 'rdbms' in 0.007 seconds.
Loaded module 'redis' in 0.003 seconds.
Loaded module 'relay' in 0.004 seconds.
Loaded module 'reservations' in 0.004 seconds.
Loaded module 'resource' in 0.008 seconds.
Loaded module 'role' in 0.005 seconds.
Loaded module 'search' in 0.002 seconds.
Loaded module 'security' in 0.003 seconds.
Loaded module 'servicebus' in 0.006 seconds.
Loaded module 'servicefabric' in 0.003 seconds.
Loaded module 'signalr' in 0.002 seconds.
Loaded module 'sql' in 0.008 seconds.
Loaded module 'sqlvm' in 0.004 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'storage' in 0.029 seconds.
Loaded module 'vm' in 0.019 seconds.
Loaded all modules in 0.314 seconds. (note: there's always an overhead with the first module loaded)
Extensions directory: '/Users/onno/.azure/cliextensions'
Found 1 extensions: ['azure-devops']
Extensions directory: '/Users/onno/.azure/cliextensions'
Extension compatibility result: is_compatible=True cli_core_version=2.0.80 min_required=2.0.69 max_required=None
Extensions directory: '/Users/onno/.azure/cliextensions'
Loaded extension 'azure-devops' in 0.039 seconds.
Event: CommandInvoker.OnPreCommandTableTruncate [<function AzCliLogging.init_command_file_logging at 0x10fc06ca0>]
az_command_data_logger : command args: devops login --debug
metadata file logging enabled - writing logs to '/Users/onno/.azure/commands'.
Event: CommandInvoker.OnPreArgumentLoad [<function register_global_subscription_argument.<locals>.add_subscription_parameter at 0x10fc5f4c0>]
Event: CommandInvoker.OnPostArgumentLoad []
Event: CommandInvoker.OnPostCommandTableCreate [<function register_ids_argument.<locals>.add_ids_arguments at 0x10fc5f550>, <function register_cache_arguments.<locals>.add_cache_arguments at 0x10fc5f670>]
Event: CommandInvoker.OnCommandTableLoaded []
Event: CommandInvoker.OnPreParseArgs [<function _documentdb_deprecate at 0x1108b1f70>]
Event: CommandInvoker.OnPostParseArgs [<function OutputProducer.handle_output_argument at 0x10f767160>, <function CLIQuery.handle_query_parameter at 0x10f7845e0>, <function register_ids_argument.<locals>.parse_ids_arguments at 0x10fc5f5e0>, <function handler at 0x1109f84c0>, <function DevCommandsLoader.post_parse_args at 0x1111e5160>]
Extensions directory: '/Users/onno/.azure/cliextensions'
Extensions directory: '/Users/onno/.azure/cliextensions'
az_command_data_logger : extension name: azure-devops
az_command_data_logger : extension version: 0.16.0
Token:
keyring.backend : Loading KWallet
keyring.backend : Loading SecretService
keyring.backend : Loading Windows
keyring.backend : Loading chainer
keyring.backend : Loading macOS
Keyring backend : keyring.backends.OS_X.Keyring (priority: 5)
Setting credential: azdevops-cli: default
Unable to use secure credential store in this environment.
Please refer to alternate methods at https://aka.ms/azure-devops-cli-auth
using Environment variable
or use 'az login'
handling generic error
cli.azure.cli.core.util : Can't store password on keychain
Can't store password on keychain
az_command_data_logger : exit code: 1
telemetry.save : Save telemetry record of length 2586 in cache
telemetry.check : Returns Positive.
telemetry.main : Begin creating telemetry upload process.
telemetry.process : Creating upload process: "/usr/local/Cellar/azure-cli/2.0.80/libexec/bin/python /usr/local/Cellar/azure-cli/2.0.80/libexec/lib/python3.8/site-packages/azure/cli/telemetry/__init__.py /Users/onno/.azure"
telemetry.process : Return from creating process
telemetry.main : Finish creating telemetry upload process.
command ran in 5.648 seconds.

[OnnoH]

Also when setting the PAT in AZURE_DEVOPS_EXT_PAT I still get the Token prompt.

And when issuing the az login first, I also get the same Can't store password on keychain error.

Related to #738? But I don't have az cli in my keychain.

[ishitam8]

@OnnoH , If you are storing PAT in environment variables, you don't need to run "az devops login" command, you can directly run other commands. Could you please verify if you are able to run any other commands?

Also, az cli doesn't store credentials in keychain. Are you sure you ran "az login" only ? Or was it "az devops login" ?

[OnnoH]

@ishitam8 With the environment set, I'm able to run any other commands like az devops project list | jq '.value[].name' and az repos list --project Servers

I ran az devops login prior to and after az login with the same result.

[ishitam8]

I am assuming you are unblocked now as you are able to run devops commands. [Since az devops project list worked for you, with fetching PAT from env variable]

We will look into the az devops login error for Mac OS. Hence, keeping this issue open.

[trajano]

I'm actually getting the sam error but on Windows 10 release preview

$ az devops login --debug
Command arguments: ['devops', 'login', '--debug']
Event: Cli.PreExecute []
Event: CommandParser.OnGlobalArgumentsCreate [<function CLILogging.on_global_arguments at 0x037A8F18>, <function OutputProducer.on_global_arguments at 0x037E1858>, <function CLIQuery.on_global_arguments at 0x037FEA98>]
Event: CommandInvoker.OnPreCommandTableCreate []
Installed command modules ['acr', 'acs', 'advisor', 'ams', 'apim', 'appconfig', 'appservice', 'aro', 'backup', 'batch', 'batchai', 'billing', 'botservice', 'cdn', 'cloud', 'cognitiveservices', 'configure', 'consumption', 'container', 'cosmosdb', 'deploymentmanager', 'dla', 'dls', 'dms', 'eventgrid', 'eventhubs', 'extension', 'feedback', 'find', 'hdinsight', 'interactive', 'iot', 'iotcentral', 'keyvault', 'kusto', 'lab', 'managedservices', 'maps', 'monitor', 'natgateway', 'netappfiles', 'network', 'policyinsights', 'privatedns', 'profile', 'rdbms', 'redis', 'relay', 'reservations', 'resource', 'role', 'search', 'security', 'servicebus', 'servicefabric', 'signalr', 'sql', 'sqlvm', 'storage', 'vm']
Loaded module 'acr' in 0.007 seconds.
Loaded module 'acs' in 0.009 seconds.
Loaded module 'advisor' in 0.003 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'ams' in 0.006 seconds.
Loaded module 'apim' in 0.003 seconds.
Loaded module 'appconfig' in 0.005 seconds.
Loaded module 'appservice' in 0.009 seconds.
Loaded module 'aro' in 0.010 seconds.
Loaded module 'backup' in 0.004 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'batch' in 0.031 seconds.
Loaded module 'batchai' in 0.004 seconds.
Loaded module 'billing' in 0.003 seconds.
Loaded module 'botservice' in 0.005 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'cdn' in 0.005 seconds.
Loaded module 'cloud' in 0.003 seconds.
Loaded module 'cognitiveservices' in 0.003 seconds.
Loaded module 'configure' in 0.003 seconds.
Loaded module 'consumption' in 0.004 seconds.
Loaded module 'container' in 0.003 seconds.
Loaded module 'cosmosdb' in 0.009 seconds.
Loaded module 'deploymentmanager' in 0.004 seconds.
Loaded module 'dla' in 0.005 seconds.
Loaded module 'dls' in 0.004 seconds.
Loaded module 'dms' in 0.003 seconds.
Loaded module 'eventgrid' in 0.003 seconds.
Loaded module 'eventhubs' in 0.004 seconds.
Loaded module 'extension' in 0.002 seconds.
Loaded module 'feedback' in 0.001 seconds.
Loaded module 'find' in 0.002 seconds.
Loaded module 'hdinsight' in 0.003 seconds.
Loaded module 'interactive' in 0.001 seconds.
Loaded module 'iot' in 0.005 seconds.
Loaded module 'iotcentral' in 0.003 seconds.
Loaded module 'keyvault' in 0.007 seconds.
Loaded module 'kusto' in 0.003 seconds.
Loaded module 'lab' in 0.004 seconds.
Loaded module 'managedservices' in 0.002 seconds.
Loaded module 'maps' in 0.002 seconds.
Loaded module 'monitor' in 0.008 seconds.
Loaded module 'natgateway' in 0.003 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'netappfiles' in 0.004 seconds.
Loaded module 'network' in 0.028 seconds.
Loaded module 'policyinsights' in 0.004 seconds.
Loaded module 'privatedns' in 0.007 seconds.
Loaded module 'profile' in 0.003 seconds.
Loaded module 'rdbms' in 0.008 seconds.
Loaded module 'redis' in 0.003 seconds.
Loaded module 'relay' in 0.005 seconds.
Loaded module 'reservations' in 0.003 seconds.
Loaded module 'resource' in 0.009 seconds.
Loaded module 'role' in 0.005 seconds.
Loaded module 'search' in 0.003 seconds.
Loaded module 'security' in 0.003 seconds.
Loaded module 'servicebus' in 0.006 seconds.
Loaded module 'servicefabric' in 0.004 seconds.
Loaded module 'signalr' in 0.003 seconds.
Loaded module 'sql' in 0.008 seconds.
Loaded module 'sqlvm' in 0.004 seconds.
Event: CommandLoader.OnLoadCommandTable []
Loaded module 'storage' in 0.043 seconds.
Loaded module 'vm' in 0.015 seconds.
Loaded all modules in 0.363 seconds. (note: there's always an overhead with the first module loaded)
Found 1 extensions: ['azure-devops']
Extension compatibility result: is_compatible=True cli_core_version=2.6.0 min_required=2.0.69 max_required=None
Extensions directory: 'C:\Users\trajano\.azure\cliextensions\azure-devops'
Loaded extension 'azure-devops' in 0.034 seconds.
Event: CommandInvoker.OnPreCommandTableTruncate [<function AzCliLogging.init_command_file_logging at 0x03EB2E40>]
az_command_data_logger : command args: devops login --debug
metadata file logging enabled - writing logs to 'C:\Users\trajano\.azure\commands'.
Event: CommandInvoker.OnPreArgumentLoad [<function register_global_subscription_argument.<locals>.add_subscription_parameter at 0x040C83D8>]
Event: CommandInvoker.OnPostArgumentLoad []
Event: CommandInvoker.OnPostCommandTableCreate [<function register_ids_argument.<locals>.add_ids_arguments at 0x040C8DF8>, <function register_cache_arguments.<locals>.add_cache_arguments at 0x040C8ED0>]
Event: CommandInvoker.OnCommandTableLoaded []
Event: CommandInvoker.OnPreParseArgs [<function _documentdb_deprecate at 0x0497E0C0>]
Event: CommandInvoker.OnPostParseArgs [<function OutputProducer.handle_output_argument at 0x037E18A0>, <function CLIQuery.handle_query_parameter at 0x037FEAE0>, <function register_ids_argument.<locals>.parse_ids_arguments at 0x040C8E88>, <function handler at 0x047DA6F0>, <function DevCommandsLoader.post_parse_args at 0x05089660>]
az_command_data_logger : extension name: azure-devops
az_command_data_logger : extension version: 0.17.0
Token:
installing keyring~=17.1.1
Unable to use secure credential store in this environment.
Please refer to alternate methods at https://aka.ms/azure-devops-cli-auth
using Environment variable
or use 'az login'
handling generic error
cli.azure.cli.core.util : _run_pip() missing 1 required positional argument: 'extension_path'
_run_pip() missing 1 required positional argument: 'extension_path'
Event: Cli.PostExecute [<function AzCliLogging.deinit_cmd_metadata_logging at 0x03EB2F60>]
az_command_data_logger : exit code: 1
telemetry.save : Save telemetry record of length 2538 in cache
telemetry.check : Negative: The C:\Users\trajano\.azure\telemetry.txt was modified at 2020-05-20 14:43:25.582457, which in less than 600.000000 s
command ran in 2.187 seconds.