search

Azure / Azurite

A lightweight server clone of Azure Storage that simulates most of the commands supported by it with minimal dependencies
MIT License
1.74k stars 309 forks source link

Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature #2381

Closed tanyunshi closed 3 months ago

tanyunshi commented 3 months ago

Which service(blob, file, queue, table) does this issue concern?

Blob

Which version of the Azurite was used?

3.25.0, 3.29.0 at least

Where do you get Azurite? (npm, DockerHub, NuGet, Visual Studio Code Extension)

git clone and then install it with npm

What's the Node.js version?

v21.7.1

What problem was encountered?

Cannot run azure durable func tutorial (https://learn.microsoft.com/en-us/azure/azure-functions/durable/quickstart-python-vscode?tabs=windows%2Cazure-cli-set-indexing-flag&pivots=python-mode-decorators) with the following error message : Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature

Executed 'Functions.http_start' (Failed, Id=abe7ab13-14ce-41c2-95bf-ca2f91524d7e, Duration=608ms) [2024-03-26T08:12:52.853Z] System.Private.CoreLib: Exception while executing function: Functions.httpstart. System.Private.CoreLib: Result: Failure Exception: Exception: {'Message': 'Something went wrong while processing your request', 'ExceptionMessage': 'Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature.', 'ExceptionType': 'DurableTask.AzureStorage.Storage.DurableTaskStorageException', 'StackTrace': ' at DurableTask.AzureStorage.Storage.AzureStorageClient.MakeStorageRequest[T](Func`3 storageRequest, String accountName, String operationName, String clientRequestId, Boolean force) in //src/DurableTask.AzureStorage/Storage/AzureStorageClient.cs:line 150\r\n at DurableTask.AzureStorage.Storage.Queue.AddMessageAsync(QueueMessage queueMessage, Nullable1 visibilityDelay, Nullable1 clientRequestId) in //src/DurableTask.AzureStorage/Storage/Queue.cs:line 54\r\n at DurableTask.AzureStorage.Messaging.TaskHubQueue.AddMessageAsync(TaskMessage taskMessage, OrchestrationInstance sourceInstance, SessionBase session) in //src/DurableTask.AzureStorage/Messaging/TaskHubQueue.cs:line 129\r\n at DurableTask.AzureStorage.AzureStorageOrchestrationService.CreateTaskOrchestrationAsync(TaskMessage creationMessage, OrchestrationStatus[] dedupeStatuses) in //src/DurableTask.AzureStorage/AzureStorageOrchestrationService.cs:line 1656\r\n at DurableTask.Core.TaskHubClient.InternalCreateOrchestrationInstanceWithRaisedEventAsync(String orchestrationName, String orchestrationVersion, String orchestrationInstanceId, Object orchestrationInput, IDictionary2 orchestrationTags, OrchestrationStatus[] dedupeStatuses, String eventName, Object eventData, Nullable1 startAt) in //src/DurableTask.Core/TaskHubClient.cs:line 619\r\n at Microsoft.Azure.WebJobs.Extensions.DurableTask.DurableClient.Microsoft.Azure.WebJobs.Extensions.DurableTask.IDurableOrchestrationClient.StartNewAsync[T](String orchestratorFunctionName, String instanceId, T input) in D:\a\_work\1\s\src\WebJobs.Extensions.DurableTask\ContextImplementations\DurableClient.cs:line 213\r\n at Microsoft.Azure.WebJobs.Extensions.DurableTask.HttpApiHandler.HandleStartOrchestratorRequestAsync(HttpRequestMessage request, String functionName, String instanceId) in D:\a\_work\1\s\src\WebJobs.Extensions.DurableTask\HttpApiHandler.cs:line 875\r\n at Microsoft.Azure.WebJobs.Extensions.DurableTask.HttpApiHandler.HandleRequestAsync(HttpRequestMessage request) in D:\a\_work\1\s\src\WebJobs.Extensions.DurableTask\HttpApiHandler.cs:line 306'}

Steps to reproduce the issue?

  1. Start azurite azurite --location .\azurite\ --debug .\azurite\debug6.log --loose
  2. In the azure function, the local settings has "AzureWebJobsStorage": "UseDevelopmentStorage=true", as suggested in the tutorial. I've also tried the connection string AccountName=devstoreaccount1;AccountKey=xxx;DefaultEndpointsProtocol=http;BlobEndpoint=http://127.0.0.1:10000/devstoreaccount1;QueueEndpoint=http://127.0.0.1:10001/devstoreaccount1;TableEndpoint=http://127.0.0.1:10002/devstoreaccount1; but I got the same error message.
  3. I trigger the orchestration task http://localhost:7071/api/orchestrators/hello_orchestrator Then I got the error as shown above.

Debug message 

2024-03-26T08:12:52.482Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: TableStorageContextMiddleware: RequestMethod=GET RequestURL=http://127.0.0.1/devstoreaccount1/TestHubNameInstances?$filter=PartitionKey%20eq%20%2731a21be6de564b6eb4d853b283997e52%27&$select=ExecutionId%2CName%2CVersion%2COutput%2CCustomStatus%2CCreatedTime%2CLastUpdatedTime%2CCompletedTime%2CRuntimeStatus%2CScheduledStartTime%2CGeneration%2CTags%2CPartitionKey%2CRowKey%2CTimestamp%2CETag RequestHeaders:{"host":"127.0.0.1:10002","user-agent":"Azure-Storage/9.3.1 (.NET Core)","accept-charset":"UTF-8","maxdataserviceversion":"3.0;NetFx","accept":"application/json; odata=minimalmetadata","x-ms-client-request-id":"a1a7d169-65ef-4c07-9e1e-81014108e093","x-ms-version":"2018-03-28","x-ms-date":"Tue, 26 Mar 2024 08:12:52 GMT","authorization":"SharedKey devstoreaccount1:J47njd5k0R/5/ACiZVzb+czpFCADm+t6VJNJUD6i/Ts="} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2024-03-26T08:12:52.482Z ce73c41a-0b31-4e16-9821-1d193b0dd510 debug: tableStorageContextMiddleware: Dispatch pattern string: /TestHubNameInstances()
2024-03-26T08:12:52.482Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=TestHubNameInstances
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 verbose: DispatchMiddleware: Dispatching request...
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: DispatchMiddleware: Operation=Table_QueryEntities
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: TableSharedKeyLiteAuthenticator:validate() Request doesn't include valid authentication header. Skip SharedKeyLite authentication.
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: TableSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: TableSharedKeyAuthenticator:validate() [STRING TO SIGN]:"GET\n\n\nTue, 26 Mar 2024 08:12:52 GMT\n/devstoreaccount1/devstoreaccount1/TestHubNameInstances"
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: TableSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:J47njd5k0R/5/ACiZVzb+czpFCADm+t6VJNJUD6i/Ts=
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: TableSharedKeyAuthenticator:validate() Signature 1 matched.
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 verbose: DeserializerMiddleware: Start deserializing...
2024-03-26T08:12:52.483Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: HandlerMiddleware: DeserializedParameters={"options":{"queryOptions":{"select":"ExecutionId,Name,Version,Output,CustomStatus,CreatedTime,LastUpdatedTime,CompletedTime,RuntimeStatus,ScheduledStartTime,Generation,Tags,PartitionKey,RowKey,Timestamp,ETag","filter":"PartitionKey eq '31a21be6de564b6eb4d853b283997e52'"},"requestId":"a1a7d169-65ef-4c07-9e1e-81014108e093"},"version":"2018-03-28"}
2024-03-26T08:12:52.485Z ce73c41a-0b31-4e16-9821-1d193b0dd510 debug: TableHandler:queryEntities() Raw response string is "{\"odata.metadata\":\"http://127.0.0.1:10002/devstoreaccount1/$metadata#Tables/@Element\",\"value\":[]}"
2024-03-26T08:12:52.485Z ce73c41a-0b31-4e16-9821-1d193b0dd510 verbose: SerializerMiddleware: Start serializing...
2024-03-26T08:12:52.486Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: Serializer: Start returning stream body.
2024-03-26T08:12:52.489Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: EndMiddleware: End response. TotalTimeInMS=7 StatusCode=200 StatusMessage=OK Headers={"server":"Azurite-Table/3.29.0","content-type":"application/json;odata=minimalmetadata","x-ms-client-request-id":"a1a7d169-65ef-4c07-9e1e-81014108e093","x-ms-request-id":"ce73c41a-0b31-4e16-9821-1d193b0dd510","x-ms-version":"2024-02-04","date":"Tue, 26 Mar 2024 08:12:52 GMT"}
2024-03-26T08:12:52.533Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: QueueStorageContextMiddleware: RequestMethod=POST RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-control-03/messages?messagettl=-1 RequestHeaders:{"host":"127.0.0.1:10001","user-agent":"Azure-Storage/9.3.1 (.NET Core)","accept":"*/*","x-ms-client-request-id":"a56c92bd-14f7-4ed3-9245-00a0f3803bdf","x-ms-version":"2018-03-28","x-ms-date":"Tue, 26 Mar 2024 08:12:52 GMT","authorization":"SharedKey devstoreaccount1:himw0TNMIEtoP/HkIT+pXIAwOzpcoyLANEhpDL+05GY=","content-length":"1437","content-type":"application/x-www-form-urlencoded"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: QueueStorageContextMiddleware: Account=devstoreaccount1 Queue=testhubname-control-03 Message=messages MessageId=undefined
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 verbose: DispatchMiddleware: Dispatching request...
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: DispatchMiddleware: Operation=Messages_Enqueue
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: QueueSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: QueueSharedKeyAuthenticator:validate() [STRING TO SIGN]:"POST\n\n\n1437\n\napplication/x-www-form-urlencoded\n\n\n\n\n\n\nx-ms-client-request-id:a56c92bd-14f7-4ed3-9245-00a0f3803bdf\nx-ms-date:Tue, 26 Mar 2024 08:12:52 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-control-03/messages\nmessagettl:-1"
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: QueueSharedKeyAuthenticator:validate() Calculated authentication header based on key1: devstoreaccount1:hjXpbOpQ2a/1mHSuNxNTv2UWJSwfZm/EEAzPfads8gs=
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: QueueSharedKeyAuthenticator:validate() Validation failed.
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: AccountSASAuthenticator:validate() Start validation against account Shared Access Signature pattern.
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: AccountSASAuthenticator:validate() Getting account properties...
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: AccountSASAuthenticator:validate() Retrieved account name from context: devstoreaccount1, queue: testhubname-control-03
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: AccountSASAuthenticator:validate() Got account properties successfully.
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: AccountSASAuthenticator:validate() Retrieved signature from URL parameter sig: undefined
2024-03-26T08:12:52.534Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: AccountSASAuthenticator:validate() Failed to get valid account SAS values from request.
2024-03-26T08:12:52.535Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: QueueSASAuthenticator:validate() Start validation against queue service Shared Access Signature pattern.
2024-03-26T08:12:52.535Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: QueueSASAuthenticator:validate() Getting account properties...
2024-03-26T08:12:52.535Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: QueueSASAuthenticator:validate() Retrieved account name from context: devstoreaccount1, queue: testhubname-control-03
2024-03-26T08:12:52.535Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: QueueSASAuthenticator:validate() Got account properties successfully.
2024-03-26T08:12:52.535Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: QueueSASAuthenticator:validate() Retrieved signature from URL parameter sig: undefined
2024-03-26T08:12:52.535Z bbf2e056-0306-4072-bc8a-4129f2c42d25 debug: QueueSASAuthenticator:validate() No signature found in request. Skip Queue service SAS validation.
2024-03-26T08:12:52.535Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature.  ErrorHTTPStatusCode=403 ErrorHTTPStatusMessage=Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature. ErrorHTTPHeaders={"x-ms-error-code":"AuthenticationFailed","x-ms-request-id":"bbf2e056-0306-4072-bc8a-4129f2c42d25","x-ms-version":"2024-02-04"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>AuthenticationFailed</Code>\n  <Message>Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature.\nRequestId:bbf2e056-0306-4072-bc8a-4129f2c42d25\nTime:2024-03-26T08:12:52.535Z</Message>\n</Error>" ErrorStack="StorageError: Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature.\n    at StorageErrorFactory.getAuthorizationFailure (C:\\Users\\A473200\\Downloads\\Azurite-3.29.0\\Azurite-3.29.0\\dist\\src\\queue\\errors\\StorageErrorFactory.js:49:16)\n    at C:\\Users\\A473200\\Downloads\\Azurite-3.29.0\\Azurite-3.29.0\\dist\\src\\queue\\middlewares\\AuthenticationMiddlewareFactory.js:23:56\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)"
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: Set HTTP code: 403
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: Set HTTP status message: Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature.
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=AuthenticationFailed
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=bbf2e056-0306-4072-bc8a-4129f2c42d25
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: Set HTTP Header: x-ms-version=2024-02-04
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: Set content type: application/xml
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>AuthenticationFailed</Code>\n  <Message>Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature.\nRequestId:bbf2e056-0306-4072-bc8a-4129f2c42d25\nTime:2024-03-26T08:12:52.535Z</Message>\n</Error>"
2024-03-26T08:12:52.536Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: EndMiddleware: End response. TotalTimeInMS=3 StatusCode=403 StatusMessage=Server failed to authenticate the request.Make sure the value of the Authorization header is formed correctly including the signature. Headers={"server":"Azurite-Queue/3.29.0","x-ms-error-code":"AuthenticationFailed","x-ms-request-id":"bbf2e056-0306-4072-bc8a-4129f2c42d25","x-ms-version":"2024-02-04","content-type":"application/xml"}

Here is the request with resp 200 ( copied from the debug log below)

2024-03-26T08:12:52.482Z ce73c41a-0b31-4e16-9821-1d193b0dd510 info: TableStorageContextMiddleware: RequestMethod=GET RequestURL=http://127.0.0.1/devstoreaccount1/TestHubNameInstances?$filter=PartitionKey%20eq%20%2731a21be6de564b6eb4d853b283997e52%27&$select=ExecutionId%2CName%2CVersion%2COutput%2CCustomStatus%2CCreatedTime%2CLastUpdatedTime%2CCompletedTime%2CRuntimeStatus%2CScheduledStartTime%2CGeneration%2CTags%2CPartitionKey%2CRowKey%2CTimestamp%2CETag RequestHeaders:{"host":"127.0.0.1:10002","user-agent":"Azure-Storage/9.3.1 (.NET Core)","accept-charset":"UTF-8","maxdataserviceversion":"3.0;NetFx","accept":"application/json; odata=minimalmetadata","x-ms-client-request-id":"a1a7d169-65ef-4c07-9e1e-81014108e093","x-ms-version":"2018-03-28","x-ms-date":"Tue, 26 Mar 2024 08:12:52 GMT","authorization":"SharedKey

Here is the request with resp 403 ( copied from the debug log below)

2024-03-26T08:12:52.533Z bbf2e056-0306-4072-bc8a-4129f2c42d25 info: QueueStorageContextMiddleware: RequestMethod=POST RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-control-03/messages?messagettl=-1 RequestHeaders:{"host":"127.0.0.1:10001","user-agent":"Azure-Storage/9.3.1 (.NET Core)","accept":"*/*","x-ms-client-request-id":"a56c92bd-14f7-4ed3-9245-00a0f3803bdf","x-ms-version":"2018-03-28","x-ms-date":"Tue, 26 Mar 2024 08:12:52 GMT","authorization":"SharedKey devstoreaccount1:himw0TNMIEtoP/HkIT+pXIAwOzpcoyLANEhpDL+05GY=","content-length":"1437","content-type":"application/x-www-form-urlencoded"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1

Have you found a mitigation/solution?

No

blueww commented 3 months ago

@tanyunshi

From the debug log:

The difference is the "Content-Type" "application/x-www-form-urlencoded" is your request is missed from your stringToSign. Per this doc, StringTosign for Queue service contains "Content-Type".

It looks the failure is caused by the StringTosign generated from your client missed "Content-Type". Would you please check the same program works on product Azure server or not? Is not work, this should be client issue. If works, please inform us and we will continue the investigation on it.

tanyunshi commented 3 months ago

Hello @blueww

Thank you for your feedback.

The same code works well with Azure Storage account (Set AzureWebJobsStorage to DefaultEndpointsProtocol=https;AccountName=serious_account_name;AccountKey=secret==;EndpointSuffix=core.windows.net in the code).

blueww commented 3 months ago

@tanyunshi

I have validated send a putmessge request to product Azure server with Content-Type: application/xml, and see the stringToSign need include "application/xml". So per my test, on product Azure server, StringToSign really will need include Content-Type. And your stringTosign doesn't has Content-Type.

So the problem is your request has Content-Type header, but the StringTosign (used to calculate sharedkey signature) calculate from your client doesn't contain Content-Type. Please check your client, and see how it generate StringTosign on putmessgae request. Why Content-Type is not included in StringTosign? It's interesting that the same program works on product Azure. However I have checked server do need Content-Type header in StringTosign. So please check with Client team to see how they generate stringTosign.

tanyunshi commented 3 months ago

Hello

Indeed I have the application/x-www-form-urlencoded in my requests and I do not know why ...
Maybe it's related to some Window configuration ( proxy ? ) :( It seems to be a sad story.

I tested the same code on my personal PC with the same dependencies ( azurite, azure core tools, python etc, in the same version ). It works fine.

I introspect all the http calls and indeed there is no application/x-www-form-urlencoded in any headers of the requests while running on my PC.

I will close the issue in a few days. Clearly not a bug from Azurite !

tanyunshi commented 3 months ago

Hi again @blueww

I confirm that my Px proxy has somehow added a header to the requests ... By bypassing the proxy for 127.0.01, everything works well. I close this issue.

Thank you again. I cannot get this solved without your hint ! :)