Getting "The process cannot access the file because it is being used by another process" errors with ~\.azure\logs\az.log

[danmacode]

Describe the bug

When I call az-cli commands from PowerShell Core inside parallel jobs, they sometimes run into python's PermissionError: [WinError 32] when accessing the log file.

Related command

I register some resource providers in a new RG with the following -Parallel loop:

$resourceProviders| ForEach-Object -Parallel {
    $SubscriptionId = $using:SubscriptionId
    az provider register --wait --subscription $SubscriptionId --namespace $_
} -ThrottleLimit 10

This is a similar loop using ThreadJob:

$jobs = @()
foreach ($rp in $resourceProviders) {
    $jobs += Start-ThreadJob -Name $rp -ScriptBlock {
        $params = $using:SubscriptionId
        az provider register --wait --subscription $SubscriptionId --namespace $rp
    }
}
Wait-Job -Job $jobs

Errors

--- Logging error ---
Traceback (most recent call last):
  File "logging\handlers.py", line 74, in emit
  File "logging\handlers.py", line 179, in doRollover
  File "logging\handlers.py", line 115, in rotate
PermissionError: [WinError 32] The process cannot access the file because it is being used by another process: 'C:\\Users\\danmacode\\.azure\\logs\\az.log' -> 'C:\\Users\\danmacode\\.azure\\logs\\az.log.1'
Call stack:
  File "<frozen runpy>", line 198, in _run_module_as_main
  File "<frozen runpy>", line 88, in _run_code
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/cli/__main__.py", line 41, in <module>
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/cli/__main__.py", line 27, in cli_main
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\knack/cli.py", line 233, in invoke
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/cli/core/commands/__init__.py", line 659, in execute
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/cli/core/commands/__init__.py", line 733, in _run_jobs_serially
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/cli/core/commands/__init__.py", line 703, in _run_job
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/cli/core/commands/__init__.py", line 336, in __call__
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/cli/core/commands/command_operation.py", line 361, in handler
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/tracing/decorator.py", line 76, in wrapper_use_tracer
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/mgmt/resource/resources/v2022_09_01/operations/_operations.py", line 8338, in get
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/_base.py", line 213, in run
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/_base.py", line 70, in send
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/_base.py", line 70, in send
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/_base.py", line 70, in send
  [Previous line repeated 2 more times]
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/mgmt/core/policies/_base.py", line 47, in send
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/policies/_redirect.py", line 181, in send
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/policies/_retry.py", line 467, in send
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/policies/_authentication.py", line 115, in send
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/_base.py", line 70, in send
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/_base.py", line 75, in send
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/core/pipeline/_tools.py", line 45, in await_result
  File "D:\a\_work\1\s\build_scripts\windows\artifacts\cli\Lib\site-packages\azure/cli/core/sdk/policies.py", line 81, in on_response
  File "logging\__init__.py", line 1477, in debug
  File "logging\__init__.py", line 1634, in _log
  File "logging\__init__.py", line 1644, in handle
  File "logging\__init__.py", line 1706, in callHandlers
  File "logging\__init__.py", line 978, in handle
  File "logging\handlers.py", line 77, in emit
Message: 'Response content:'
Arguments: ()

Issue script & Debug output

No debug output.

Expected behavior

There shouldn't be a permission error when multiple processes or threads try to write to the az.log file simultaneously.

Environment Summary

azure-cli                         2.65.0

core                              2.65.0
telemetry                          1.1.0

Extensions:
account                            0.2.5
automation                       1.0.0b1
init                               0.1.0
next                               0.1.3

Dependencies:
msal                              1.31.0
azure-mgmt-resource               23.1.1

Python location 'C:\Program Files\Microsoft SDKs\Azure\CLI2\python.exe'
Extensions directory 'C:\Users\danmacode\.azure\cliextensions'

Python (Windows) 3.11.8 (tags/v3.11.8:db85d51, Feb  6 2024, 22:03:32) [MSC v.1937 64 bit (AMD64)]

Legal docs and information: aka.ms/AzureCliLegal


Your CLI is up-to-date.

Additional context

No response

[yonzhan]

Thank you for opening this issue, we will look into it.

[microsoft-github-policy-service]

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @josephkwchan, @jennyhunter-msft.