Azure / azure-cli

Azure Command-Line Interface
MIT License
3.98k stars 2.95k forks source link

Testing local Azure Function (Python) + VS Code + Azurite error: Token Expired #29707

Open SeaDude opened 1 month ago

SeaDude commented 1 month ago

Describe the bug

I have a local Azure Function created using VS Code. I have the Azurite Extension installed and started. I use function core tools in my VS Code terminal to publish them to Azure. The Functions have already been published and are working, but I want to enhance and speed up the dev/debug process so I want to test locally.

Related command

Any ideas?

Errors

FUNCTION TRIGGERED BY LOCAL QUEUE MESSAGE UPLOADED TO AZURE STORAGE EXPLORER

[2024-08-12T00:29:36.996Z] Executing 'Functions.json-proc' (Reason='New queue message detected on 'q-json-proc'.', Id=1cc65635-cb6e-4e3e-a940-d4c94a96a87a) [2024-08-12T00:29:37.000Z] Trigger Details: MessageId: 1c075415-f6c1-459e-9708-bf2915548df6, DequeueCount: 1, InsertedOn: 2024-08-12T00:29:36.000+00:00 [2024-08-12T00:29:37.060Z] Received FunctionInvocationRequest, request ID: e0dc082f-2f66-43e2-a7a7-5e776a7b8f1d, function ID: b3e8fc86-e5d7-4e45-bae9-a9b6d2337096, function name: json-proc, invocation ID: 1cc65635-cb6e-4e3e-a940-d4c94a96a87a, function type: async, timestamp (UTC): 2024-08-12 00:29:37.057901

[2024-08-12T00:29:37.076Z] ManagedIdentityCredential will use IMDS

[2024-08-12T00:29:37.076Z] #### ContainerClient successfully created. [2024-08-12T00:29:37.076Z] #### Raw blob URL: http://127.0.0.1:10001/devstoreaccount1/trigger/test.png [2024-08-12T00:29:37.076Z] No environment configuration found. [2024-08-12T00:29:37.076Z] ### Credential Retrieved [2024-08-12T00:29:37.076Z] ### Container Client Created

LOCAL AZURE FUNCTION (PYTHON) REQUESTING CREDENTIAL VIA AzureDefaultCredential()

[2024-08-12T00:29:37.076Z] Request URL: 'http://169.254.169.254/metadata/identity/oauth2/token?api-version=REDACTED&resource=REDACTED' Request method: 'GET' Request headers: 'User-Agent': 'azsdk-python-identity/1.16.0 Python/3.9.5 (Windows-10-10.0.19045-SP0)' No body was attached to the request

[2024-08-12T00:29:37.076Z] #### Credential successfully created [2024-08-12T00:29:38.360Z] DefaultAzureCredential acquired a token from AzureCliCredential

REQUEST SENT TO INTERACT WITH AZURITE (LIST BLOBS)

[2024-08-12T00:29:38.360Z] Request URL: 'https://127.blob.core.windows.net/int-ocr-json?restype=REDACTED&comp=REDACTED' Request method: 'GET' Request headers: 'x-ms-version': 'REDACTED' 'Accept': 'application/xml' 'x-ms-date': 'REDACTED' 'x-ms-client-request-id': 'f48bb27b-5841-11ef-8111-0025909ba531' 'User-Agent': 'azsdk-python-storage-blob/12.20.0 Python/3.9.5 (Windows-10-10.0.19045-SP0)' 'Authorization': 'REDACTED' No body was attached to the request

RECEIVED STATUS 401

[2024-08-12T00:29:39.184Z] Response status: 401 Response headers: 'Content-Length': '402' 'Content-Type': 'application/xml' 'Server': 'Microsoft-HTTPAPI/2.0' 'x-ms-request-id': 'd9847442-301e-003a-664e-ecbaea000000' 'x-ms-error-code': 'InvalidAuthenticationInfo' 'WWW-Authenticate': 'Bearer authorization_uri=https://login.microsoftonline.com//oauth2/authorize resource_id=https://storage.azure.com' 'Date': 'Mon, 12 Aug 2024 00:29:38 GMT'

TOKEN ERROR

NOTE: THE PATH C:\Users\VSSADM~1\ DOES NOT EXIST ON THIS MACHINE

[2024-08-12T00:29:41.713Z] AzureCliCredential.get_token failed: ERROR: The command failed with an unexpected error. Here is the traceback: ERROR: Get Token request returned http error: 400 and server response: {"error":"interaction_required","error_description":"AADSTS70043: The refresh token has expired or is invalid due to sign-in frequency checks by conditional access. The token was issued on 2024-05-24T00:02:02.2994836Z and the maximum allowed lifetime for this request is 300. Trace ID: 202e44bc-6a1b-489f-a506-c381cac94d00 Correlation ID: 04fc672f-0bb7-4b42-993d-11e45b6ac04a Timestamp: 2024-08-12 00:29:41Z","error_codes":[70043],"timestamp":"2024-08-12 00:29:41Z","trace_id":"202e44bc-6a1b-489f-a506-c381cac94d00","correlation_id":"04fc672f-0bb7-4b42-993d-11e45b6ac04a","suberror":"token_expired"} Traceback (most recent call last): File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-yccaebu4\knack\cli.py", line 233, in invoke File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-8u6uejh7\azure\cli\core\commands__init.py", line 664, in execute File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-8u6uejh7\azure\cli\core\commands__init__.py", line 727, in _run_jobs_serially File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-8u6uejh7\azure\cli\core\commands\init.py", line 720, in _run_job File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-rg200gj8\six.py", line 703, in reraise
File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-8u6uejh7\azure\cli\core\commands\
init.py", line 698, in _run_job File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-8u6uejh7\azure\cli\core\commands\init.py", line 331, in call File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-8u6uejh7\azure\cli\core\init__.py", line 816, in default_command_handler File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-7as_bwui\azure\cli\command_modules\profile\custom.py", line 79, in get_access_token File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-8u6uejh7\azure\cli\core_profile.py", line 676, in get_raw_token File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-8u6uejh7\azure\cli\core_profile.py", line 1065, in retrieve_token_for_user File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\authentication_context.py", line 145, in acquire_token File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\authentication_context.py", line 128, in _acquire_token File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\authentication_context.py", line 143, in token_func File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\token_request.py", line 347, in get_token_from_cache_with_refresh File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\token_request.py", line 127, in _find_token_from_cache File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\cache_driver.py", line 199, in find File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\cache_driver.py", line 184, in _refresh_entry_if_necessary File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\cache_driver.py", line 160, in _acquire_new_token_from_mrrt File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\token_request.py", line 137, in _get_token_with_token_response File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\token_request.py", line 339, in _get_token_with_refresh_token File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\token_request.py", line 112, in _oauth_get_token File "C:\Users\VSSADM~1\AppData\Local\Temp\pip-unpacked-wheel-fnzsbt3h\adal\oauth2_client.py", line 289, in get_token adal.adal_error.AdalError: Get Token request returned http error: 400 and server response: {"error":"interaction_required","error_description":"AADSTS70043: The refresh token has expired or is invalid due to sign-in frequency checks by conditional access. The token was issued on 2024-05-24T00:02:02.2994836Z and the maximum allowed lifetime for this request is 300. Trace ID: 202e44bc-6a1b-489f-a506-c381cac94d00 Correlation ID: 04fc672f-0bb7-4b42-993d-11e45b6ac04a Timestamp: 2024-08-12 00:29:41Z","error_codes":[70043],"timestamp":"2024-08-12 00:29:41Z","trace_id":"202e44bc-6a1b-489f-a506-c381cac94d00","correlation_id":"04fc672f-0bb7-4b42-993d-11e45b6ac04a","suberror":"token_expired"} To open an issue, please run: 'az feedback'

FUNCTION EXECUTION COMPLETED

[2024-08-12T00:29:41.766Z] Executed 'Functions.json-proc' (Succeeded, Id=1cc65635-cb6e-4e3e-a940-d4c94a96a87a, Duration=4793ms)

QUEUE DELETED

[2024-08-12T00:29:41.811Z] Request [66f67efc-8dcf-4ecc-b4c3-df4a28b90869] DELETE http://127.0.0.1:10001/devstoreaccount1/q-json-proc/messages/1c075415-f6c1-459e-9708-bf2915548df6?popreceipt=MTJBdWcyMDI0MDA6Mjk6MzY0Njg4 [2024-08-12T00:29:41.813Z] x-ms-version:2018-11-09 [2024-08-12T00:29:41.815Z] Accept:application/xml [2024-08-12T00:29:41.816Z] x-ms-client-request-id:66f67efc-8dcf-4ecc-b4c3-df4a28b90869 [2024-08-12T00:29:41.818Z] x-ms-return-client-request-id:true [2024-08-12T00:29:41.819Z] User-Agent:azsdk-net-Storage.Queues/12.17.1 (.NET 6.0.29; Microsoft Windows 10.0.19045) [2024-08-12T00:29:41.820Z] x-ms-date:Mon, 12 Aug 2024 00:29:41 GMT [2024-08-12T00:29:41.821Z] Authorization:REDACTED [2024-08-12T00:29:41.823Z] client assembly: Azure.Storage.Queues [2024-08-12T00:29:41.826Z] Response [66f67efc-8dcf-4ecc-b4c3-df4a28b90869] 204 No Content (00.0s) [2024-08-12T00:29:41.827Z] Server:Azurite-Queue/3.31.0 [2024-08-12T00:29:41.829Z] x-ms-client-request-id:66f67efc-8dcf-4ecc-b4c3-df4a28b90869 [2024-08-12T00:29:41.831Z] x-ms-request-id:c2dd5e7c-365c-4cc2-8702-f08829e55a00 [2024-08-12T00:29:41.832Z] x-ms-version:2024-08-04 [2024-08-12T00:29:41.834Z] Date:Mon, 12 Aug 2024 00:29:41 GMT [2024-08-12T00:29:41.835Z] Connection:keep-alive [2024-08-12T00:29:41.837Z] Keep-Alive:REDACTED

Issue script & Debug output

See above

Expected behavior

I'd be able to securely interact with Azure Storage Explorer (via Azurite) so I can quickly and easily debug Python Functions locally.

Environment Summary

azure-cli 2.63.0 core 2.63.0 telemetry 1.1.0

Dependencies: msal 1.30.0 azure-mgmt-resource 23.1.1

Python location 'C:\Program Files (x86)\Microsoft SDKs\Azure\CLI2\python.exe' Extensions directory 'C:\Users\user7.azure\cliextensions' Python (Windows) 3.11.8 (tags/v3.11.8:db85d51, Feb 6 2024, 21:52:07) [MSC v.1937 32 bit (Intel)] Your CLI is up-to-date.

Additional context

Thank you

yonzhan commented 1 month ago

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

jiasli commented 1 month ago

Azure CLI started to use MSAL since 2.30.0 (released on November 02, 2021): https://learn.microsoft.com/en-us/cli/azure/msal-based-azure-cli. MSAL-based Azure CLI cannot interact with ADAL's token cache. ADAL-based Azure CLI is no longer supported.

Judging from the call stack, ADAL-based Azure CLI is used. Please update to the latest Azure CLI.

Also, according to the error message:

AADSTS70043: The refresh token has expired or is invalid due to sign-in frequency checks by conditional access. The token was issued on 2024-05-24T00:02:02.2994836Z and the maximum allowed lifetime for this request is 300.

The refresh token was retrieved nearly 3 months ago. If you have to use ADAL-based Azure CLI, please run az login again with ADAL-based Azure CLI.

SeaDude commented 1 month ago

Will test later on today and report back. Thank you

SeaDude commented 1 month ago

Similar error, no change after updating az cli.

az --version:

azure-cli                         2.63.0

core                              2.63.0
telemetry                          1.1.0

Dependencies:
msal                              1.30.0
azure-mgmt-resource               23.1.1

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

Python (Windows) 3.11.8 (tags/v3.11.8:db85d51, Feb  6 2024, 21:52:07) [MSC v.1937 32 bit (Intel)]

Legal docs and information: aka.ms/AzureCliLegal
Legal docs and information: aka.ms/AzureCliLegal

Your CLI is up-to-date.

LOG:

## FUNCTION TRIGGERED

[2024-08-13T02:32:53.529Z] Executing 'Functions.json-proc' (Reason='New queue message detected on 'q-json-proc'.', Id=ad82b86e-4392-4b13-9f37-b42ac250643e)
[2024-08-13T02:32:53.532Z] Trigger Details: MessageId: b072e19a-1d3e-497a-ac48-55a51e6d69f0, DequeueCount: 1, InsertedOn: 2024-08-13T02:32:52.000+00:00
[2024-08-13T02:32:53.590Z] Received FunctionInvocationRequest, request ID: 1ca0e735-240d-485a-9472-ad2ef05abf99, function ID: 6c1aee9c-80fa-4491-a152-8f1c221847bf, function name: json-proc, invocation ID: ad82b86e-4392-4b13-9f37-b42ac250643e, function type: async, timestamp (UTC): 2024-08-13 02:32:53.589182
[2024-08-13T02:32:53.606Z] No environment configuration found.
[2024-08-13T02:32:53.606Z] ### Credential Retrieved
[2024-08-13T02:32:53.606Z] Request URL: 'http://169.254.169.254/metadata/identity/oauth2/token?api-version=REDACTED&resource=REDACTED'
Request method: 'GET'
Request headers:
    'User-Agent': 'azsdk-python-identity/1.16.0 Python/3.9.5 (Windows-10-10.0.19045-SP0)'
No body was attached to the request
[2024-08-13T02:32:53.606Z] ManagedIdentityCredential will use IMDS
[2024-08-13T02:32:53.606Z] ### Container Client Created
[2024-08-13T02:32:53.606Z] #### ContainerClient successfully created.
[2024-08-13T02:32:53.606Z] #### Raw blob URL: http://127.0.0.1:10001/devstoreaccount1/trigger/test.png
[2024-08-13T02:32:53.606Z] ### Blobs Listing Initiated
[2024-08-13T02:32:53.606Z] #### Credential successfully created
[2024-08-13T02:32:53.606Z] ### Queue Message Parsed
[2024-08-13T02:32:55.328Z] DefaultAzureCredential acquired a token from AzureCliCredential

## THIS URL DOESN"T LOOK LEGIT
## SHOULD IT BE http://127.0.0.1:1001/devstoreaccount1/int-ocr-json?

[2024-08-13T02:32:55.329Z] Request URL: 'https://127.blob.core.windows.net/int-ocr-json?restype=REDACTED&comp=REDACTED'
Request method: 'GET'
Request headers:
    'x-ms-version': 'REDACTED'
    'Accept': 'application/xml'
    'x-ms-date': 'REDACTED'
    'x-ms-client-request-id': '57a26610-591c-11ef-bd1c-0025909ba531'
    'User-Agent': 'azsdk-python-storage-blob/12.20.0 Python/3.9.5 (Windows-10-10.0.19045-SP0)'
    'Authorization': 'REDACTED'
No body was attached to the request

## STATUS 401 

[2024-08-13T02:32:56.138Z] Response status: 401
Response headers:
    'Content-Length': '402'
    'Content-Type': 'application/xml'
    'Server': 'Microsoft-HTTPAPI/2.0'
    'x-ms-request-id': '9eab5865-901e-001c-7429-edf2f2000000'
    'x-ms-error-code': 'InvalidAuthenticationInfo'
    'WWW-Authenticate': 'Bearer authorization_uri=https://login.microsoftonline.com/ae5adae2-cf22-4a32-8e28-2b456b288338/oauth2/authorize resource_id=https://storage.azure.com'
    'Date': 'Tue, 13 Aug 2024 02:32:55 GMT'

## ERROR: I DID RUN AZ LOGIN 2x, NO CHANGE

[2024-08-13T02:32:58.097Z] AzureCliCredential.get_token failed: Please run 'az login' to set up an account
[2024-08-13T02:32:58.097Z] ### Error: Please run 'az login' to set up an account
[2024-08-13T02:32:58.139Z] Executed 'Functions.json-proc' (Succeeded, Id=ad82b86e-4392-4b13-9f37-b42ac250643e, Duration=4641ms)

## DELETE QUEUE MESSAGE

[2024-08-13T02:32:58.175Z] Request [182de8fe-feb6-45f2-8b3e-2e3dc010f223] DELETE http://127.0.0.1:10001/devstoreaccount1/q-json-proc/messages/b072e19a-1d3e-497a-ac48-55a51e6d69f0?popreceipt=MTNBdWcyMDI0MDI6MzI6NTM3YjJl
[2024-08-13T02:32:58.177Z] x-ms-version:2018-11-09
[2024-08-13T02:32:58.179Z] Accept:application/xml
[2024-08-13T02:32:58.181Z] x-ms-client-request-id:182de8fe-feb6-45f2-8b3e-2e3dc010f223
[2024-08-13T02:32:58.182Z] x-ms-return-client-request-id:true
[2024-08-13T02:32:58.184Z] User-Agent:azsdk-net-Storage.Queues/12.17.1 (.NET 6.0.29; Microsoft Windows 10.0.19045)
[2024-08-13T02:32:58.185Z] x-ms-date:Tue, 13 Aug 2024 02:32:58 GMT
[2024-08-13T02:32:58.186Z] Authorization:REDACTED
[2024-08-13T02:32:58.188Z] client assembly: Azure.Storage.Queues
[2024-08-13T02:32:58.191Z] Response [182de8fe-feb6-45f2-8b3e-2e3dc010f223] 204 No Content (00.0s)
[2024-08-13T02:32:58.192Z] Server:Azurite-Queue/3.31.0
[2024-08-13T02:32:58.194Z] x-ms-client-request-id:182de8fe-feb6-45f2-8b3e-2e3dc010f223
[2024-08-13T02:32:58.195Z] x-ms-request-id:40201a19-c720-47b7-9b37-dd813c3d9dbc
[2024-08-13T02:32:58.197Z] x-ms-version:2024-08-04
[2024-08-13T02:32:58.198Z] Date:Tue, 13 Aug 2024 02:32:58 GMT
[2024-08-13T02:32:58.199Z] Connection:keep-alive
[2024-08-13T02:32:58.200Z] Keep-Alive:REDACTED