There is a race condition in the get_cache_dir function in _file_cache.py. If two instances of the CLI are launched at nearly the same time, they will race to create the SDK cache directory. One will win, and the other will throw a FileExistsError.
Proposed Fix
Add exist_ok=True to the os.makedirs call in _file_cache.py:
As a workaround, I can run any single az devops command to create the cache dir. Then, the race condition is no longer triggered because the cache dir already exists.
Repro Steps
This is difficult to repro on my local workstation because of thread scheduler variability, but it seems to repro pretty reliably in a CI pipeline. Here's a minimal ADO pipeline to illustrate the issue:
trigger: none
pr: none
steps:
- pwsh: |
# Uncomment to make this issue go away (issue does not repro if the cache dir already exists)
#az devops project show -p my-proj-name
$commonArgs = @(
"artifacts", "universal", "download"
"--organization", "https://microsoft.visualstudio.com/"
"--project", "my-proj-name"
"--scope", "project"
"--feed", "my-feed-name"
)
$pkg1Args = $commonArgs + @(
"--name", "test-upack"
"--version", "1.0.0"
"--path", '$(Build.ArtifactStagingDirectory)/test-upack'
)
$pkg2Args = $commonArgs + @(
"--name", "test-upack-two"
"--version", "1.0.0"
"--path", '$(Build.ArtifactStagingDirectory)/test-upack-two'
)
# Start both downloads in parallel
$proc1 = Start-Process -NoNewWindow -FilePath az -ArgumentList $pkg1Args -PassThru
$proc2 = Start-Process -NoNewWindow -FilePath az -ArgumentList $pkg2Args -PassThru
Wait-Process $proc1.Id,$proc2.Id
env:
AZURE_DEVOPS_EXT_PAT: $(System.AccessToken)
And here is the output from the above pipeline. As you can see, one of the command instances throws a FileExistsError while the other completes successfully and emits a JSON object with info about the downloaded package.
ERROR: The command failed with an unexpected error. Here is the traceback:
ERROR: [Errno 17] File exists: '/home/vsts/.azure-devops/python-sdk/cache'
Traceback (most recent call last):
File "/opt/az/lib/python3.8/site-packages/knack/cli.py", line 231, in invoke
cmd_result = self.invocation.execute(args)
File "/opt/az/lib/python3.8/site-packages/azure/cli/core/commands/__init__.py", line 556, in execute
self.commands_loader.load_arguments(command)
File "/opt/az/lib/python3.8/site-packages/azure/cli/core/__init__.py", line 515, in load_arguments
command_table[command].load_arguments() # this loads the arguments via reflection
File "/opt/az/lib/python3.8/site-packages/azure/cli/core/commands/__init__.py", line 313, in load_arguments
super(AzCliCommand, self).load_arguments()
File "/opt/az/lib/python3.8/site-packages/knack/commands.py", line 104, in load_arguments
cmd_args = self.arguments_loader()
File "/opt/az/lib/python3.8/site-packages/azure/cli/core/commands/command_operation.py", line 125, in arguments_loader
op = self.get_op_handler(self.op_path)
File "/opt/az/lib/python3.8/site-packages/azure/cli/core/commands/command_operation.py", line 59, in get_op_handler
handler = import_module(mod_to_import)
File "/opt/az/lib/python3.8/importlib/__init__.py", line 127, in import_module
return _bootstrap._gcd_import(name[level:], package, level)
File "<frozen importlib._bootstrap>", line 1014, in _gcd_import
File "<frozen importlib._bootstrap>", line 991, in _find_and_load
File "<frozen importlib._bootstrap>", line 975, in _find_and_load_unlocked
File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
File "<frozen importlib._bootstrap_external>", line 843, in exec_module
File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
File "/opt/az/azcliextensions/azure-devops/azext_devops/dev/artifacts/universal.py", line 9, in <module>
from azext_devops.dev.common.services import resolve_instance, resolve_instance_and_project
File "/opt/az/azcliextensions/azure-devops/azext_devops/dev/common/services.py", line 13, in <module>
from azext_devops.devops_sdk.connection import Connection
File "/opt/az/azcliextensions/azure-devops/azext_devops/devops_sdk/connection.py", line 5, in <module>
from ._file_cache import RESOURCE_CACHE as RESOURCE_FILE_CACHE
File "/opt/az/azcliextensions/azure-devops/azext_devops/devops_sdk/_file_cache.py", line 113, in <module>
DEFAULT_CACHE_DIR = get_cache_dir()
File "/opt/az/azcliextensions/azure-devops/azext_devops/devops_sdk/_file_cache.py", line 108, in get_cache_dir
os.makedirs(azure_devops_cache_dir)
File "/usr/bin/../../opt/az/lib/python3.8/os.py", line 223, in makedirs
mkdir(name, mode)
FileExistsError: [Errno 17] File exists: '/home/vsts/.azure-devops/python-sdk/cache'
To open an issue, please run: 'az feedback'
{
"ManifestId": "0B8F236189D4B34F6180806225788D5CE118EFB0928ED6E0E2712E3D352DF7DE01",
"PackageSize": 184,
"SuperRootId": "2BB1E6CFD3F78B745AC71B94BA290B594E5AEBBA8B648EA0CB267EB1D5AC8C3302",
"Version": "1.0.0"
}
There is a race condition in the
get_cache_dir
function in _file_cache.py. If two instances of the CLI are launched at nearly the same time, they will race to create the SDK cache directory. One will win, and the other will throw aFileExistsError
.Proposed Fix
Add
exist_ok=True
to theos.makedirs
call in _file_cache.py:https://github.com/Azure/azure-devops-cli-extension/blob/0267b759fc9a1a584015973193affdfd8ea4969b/azure-devops/azext_devops/devops_sdk/_file_cache.py#L117
Workaround
As a workaround, I can run any single
az devops
command to create the cache dir. Then, the race condition is no longer triggered because the cache dir already exists.Repro Steps
This is difficult to repro on my local workstation because of thread scheduler variability, but it seems to repro pretty reliably in a CI pipeline. Here's a minimal ADO pipeline to illustrate the issue:
And here is the output from the above pipeline. As you can see, one of the command instances throws a
FileExistsError
while the other completes successfully and emits a JSON object with info about the downloaded package.