encountering 403 when trying to update the properties

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

blob

Which version of the Azurite was used?

3.15.0

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

npm

What's the Node.js version?

16.13.2

What problem was encountered?

We are using the Azurite for testing our application. We have a spark application that uses AzureNativeFileSystem (part of azure hadoop 2.7.3 package, Maven Repository: https://mvnrepository.com/artifact/org.apache.hadoop/hadoop-azure/2.7.3) With the help of the above library, mkdir calls are successful when using the azurite emulator. However, when it tries to delete or create an object, we get the 403 exceptions. We are using the same devstoreaccount1 account credentials for all operations. We can see that the 403 errors are encountered when the above library tries to update the last modification time (or properties) for the parent folder where it tries to create an object

In the below, we can see that the HEAD succeeds while PUT on the properties return the 403.

127.0.0.1 - - [10/Feb/2022:08:51:34 +0000] "HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 HTTP/1.1" 200 0 127.0.0.1 - - [10/Feb/2022:08:51:34 +0000] "HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 HTTP/1.1" 200 0 127.0.0.1 - - [10/Feb/2022:08:51:34 +0000] "PUT /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85?comp=properties HTTP/1.1" 403 -

Steps to reproduce the issue?

Using hadoop-azure 2.7.3 Debug logs are attached. debug.log

If possible, please provide the debug log using the -d parameter, replacing \<pathtodebuglog> with an appropriate path for your OS, or review the instructions for docker containers:

-d "<pathtodebuglog>"

Please be sure to remove any PII or sensitive information before sharing!
The debug log will log raw request headers and bodies, so that we can replay these against Azurite using REST and create tests to validate resolution.

Have you found a mitigation/solution?

Using Azurite 2.7

Other information:

Without any changes in our code, we can continue the test cases by using Azurite 2.7 or now deprecated Azure Storage Emulator suggesting the problem is specific to Azurite 3.x The creates with az cli works fine.

@pimehr

From the debug log, the 403 failure request is trying to put a blob properties with name as "dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85", in "Account=devstoreaccount1 Container=sparkconnectortests" The error is caused by the shared key signature not match.

I have tried to create and update properties on a blob with same name on Azurite 3.15.0 on my local machine, and it works well. (I test with .net SDK) It looks it's caused by the request send to Azurite has a wrong shared key signature.

Please share:

if this is the correct blob name: "dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85"
How you start Azurite: the start command and any customized config?
How the shared key signature is calculated, is it in the right way: https://docs.microsoft.com/en-us/rest/api/storageservices/authorize-with-shared-key#blob-queue-and-file-services-shared-key-authorization

Thanks Wei for looking into it. Please find the answers below:

if this is the correct blob name: "dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85" Yes, that is correct. Just a previous request to this blob resulted in 200 indicating that blob is indeed present.
How you start Azurite: the start command and any customized config? No special config. This is the command I used: azurite --location c:\azuriteDebug --debug c:\azuriteDebug\debug.log
How the shared key signature is calculated, is it in the right way: https://docs.microsoft.com/en-us/rest/api/storageservices/authorize-with-shared-key#blob-queue-and-file-services-shared-key-authorization This one is taken care by the library we are using so I am not sure. In the debug logs attached, we can see the calculated key to be different than the one sent by the library. What should be the correct key for this request? Do we have any tool where we can check this?

2022-02-10T08:51:34.301Z 46838a57-3210-472a-9b0c-fbe04ad0e739 info: BlobStorageContextMiddleware: RequestMethod=PUT RequestURL=http://127.0.0.1/devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85?comp=properties RequestHeaders:{"accept":"application/xml","accept-charset":"UTF-8","content-type":"","x-ms-version":"2014-02-14","user-agent":"Azure-Storage/2.0.0 (JavaJRE 1.8.0_311; Windows10 10.0)","x-ms-client-request-id":"bcc45ece-9c02-48dc-a0dd-b517acc43a7a","x-ms-date":"Thu, 10 Feb 2022 08:51:34 GMT","authorization":"SharedKey devstoreaccount1:ykJa6wFBLKfiSgWc0gDtcNIpQkq8KBBQ9mEMQvvYEUc=","host":"127.0.0.1:10000","connection":"keep-alive","content-length":"0"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1

2022-02-10T08:51:34.302Z 46838a57-3210-472a-9b0c-fbe04ad0e739 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"PUT\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:bcc45ece-9c02-48dc-a0dd-b517acc43a7a\nx-ms-date:Thu, 10 Feb 2022 08:51:34 GMT\nx-ms-version:2014-02-14\n/devstoreaccount1/devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85\ncomp:properties" 2022-02-10T08:51:34.302Z 46838a57-3210-472a-9b0c-fbe04ad0e739 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:uQ0cTC2iNe8vpKbpUUF++oq3e16/AxHZkXyBMnMZMu4=

@pimehr Look more into the log, and compare it with my success send blob properties log, I find this might come from your request has following 3 more headers than mine. Could you share why the 3 headers are added, like why set content-type to empty?

"accept":"application/xml", "accept-charset":"UTF-8", "content-type":"",

I still need to see what kind of StringToSign the client generated, to know what's the issue. Could you share which Azure Storage SDK you use to send the request? I would like to view the SDK code to know more about it.

We are using the following sdk: https://mvnrepository.com/artifact/org.apache.hadoop/hadoop-azure/2.7.3

More specifically, copyFromLocalFile function from the same which copies the local file to the azure blob endpoint.

@pimehr As we discussed, you will add more info like Azurite 2.7 log, and I will look into it.

Hi Wei, Looks like Azurite 2.7 isn't generating the debug logs

Is there any other log from Azurite 2.7 for the success request?

Just the console logs:

PS C:\Users\pimehr\azurite> azurite --location c:\azuriteDebug --debug c:\azuriteDebug\debug.log

() () _ __ | | ____ | _ ( ) | | |/ ) ( ) _ | | | | |/ /| || | | | | | || __| || |(___)/|| || _))

Azurite, Version 2.7.0 A lightweight server clone of Azure Storage

Azure Table Storage Emulator listening on port 10002 Azure Queue Storage Emulator listening on port 10001 Azure Blob Storage Emulator listening on port 10000 HEAD /devstoreaccount1/sparkconnectortests?restype=container 200 11.952 ms - 0 GET /devstoreaccount1/sparkconnectortests?restype=container&comp=list&include=metadata&delimiter=%2F 200 6.696 ms - 1018HEAD /devstoreaccount1/sparkconnectortests/dummyaccount 200 2.298 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount 200 1.129 ms - 0 GET /devstoreaccount1/sparkconnectortests?restype=container&comp=list&include=metadata&prefix=dummyaccount%2F&delimiter=%2F 200 2.255 ms - 1049 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== 200 0.698 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== 200 0.768 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount 200 0.616 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount 200 1.072 ms - 0 GET /devstoreaccount1/sparkconnectortests?restype=container&comp=list&include=metadata&prefix=dummyaccount%2FAgAAAA%3D%3D%2F&delimiter=%2F 200 2.568 ms - 2746 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos 200 0.683 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos 200 0.608 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== 200 0.736 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== 200 0.575 ms - 0 GET /devstoreaccount1/sparkconnectortests?restype=container&comp=list&include=metadata&prefix=dummyaccount%2FAgAAAA%3D%3D%2FAgAAAIUFBKE%3D.Cosmos%2F&delimiter=%2F 200 1.716 ms - 1216 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 200 0.731 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 200 0.384 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos 200 0.490 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos 200 0.458 ms - 0 GET /devstoreaccount1/sparkconnectortests?restype=container&comp=list&include=metadata&prefix=dummyaccount%2FAgAAAA%3D%3D%2FAgAAAIUFBKE%3D.Cosmos%2FPartitionId%3Dff11b509-7bd9-4234-aeac-4f5f4e134c85%2F&delimiter=%2F 200 2.573 ms - 3674 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_1.Root 200 0.550 ms - 33964 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_1.Root 202 2.294 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_2.Metadata 200 0.488 ms - 8 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_2.Metadata 202 1.200 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_8_14.HybridRowSchema 200 0.427 ms - 58625 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_8_14.HybridRowSchema 202 1.619 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 200 0.456 ms - 0 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 202 1.396 ms - 0 PUT /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos?comp=properties 200 1.771 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos 200 0.578 ms - 0 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos 202 0.989 ms - 0 PUT /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==?comp=properties 200 0.686 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet 200 0.426 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet 200 0.456 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== 200 0.378 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== 200 0.429 ms - 0 GET /devstoreaccount1/sparkconnectortests?restype=container&comp=list&include=metadata&prefix=dummyaccount%2FAgAAAA%3D%3D%2FAgAAAIUFBKE%3D.Partitioned.Parquet%2F&delimiter=%2F 200 1.921 ms - 1255 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 200 0.543 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 200 0.452 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet 200 0.449 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet 200 0.410 ms - 0 GET /devstoreaccount1/sparkconnectortests?restype=container&comp=list&include=metadata&prefix=dummyaccount%2FAgAAAA%3D%3D%2FAgAAAIUFBKE%3D.Partitioned.Parquet%2FPartitionId%3Dff11b509-7bd9-4234-aeac-4f5f4e134c85%2F&delimiter=%2F 200 2.841 ms - 3765 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_0_0.snappy.Parquet 200 0.609 ms - 4834 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_0_0.snappy.Parquet 202 1.217 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_0_1.snappy.Parquet 200 0.854 ms - 4879 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_0_1.snappy.Parquet 202 1.025 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_0_3.snappy.Parquet 200 0.444 ms - 4372 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85/0_0_3.snappy.Parquet 202 1.190 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 200 0.415 ms - 0 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 202 1.141 ms - 0 PUT /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet?comp=properties 200 0.650 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet 200 0.423 ms - 0 DELETE /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Partitioned.Parquet 202 0.988 ms - 0 PUT /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==?comp=properties 200 0.580 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.RootMetadata 200 0.578 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.RootMetadata 200 0.395 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== 200 0.438 ms - 0 HEAD /devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== 200 0.452 ms - 0

HI @blueww , I think I know where the problem is. I reproed the issue again with Azurite 3.x. I checked the string which was signed by the application and the azurite to verify the signature. From the application: PUT\n\n\n0\n\n\n\n\n\n\n\n\nx-ms-client-request-id:3ebb0d3e-cbaf-4fa9-8cd4-5c06ec66c592\nx-ms-date:Wed, 23 Feb 2022 04:25:33 GMT\nx-ms-version:2014-02-14\n/devstoreaccount1/devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos\ncomp:properties

From Azurite (as seen in the logs): "PUT\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:3ebb0d3e-cbaf-4fa9-8cd4-5c06ec66c592\nx-ms-date:Wed, 23 Feb 2022 04:25:33 GMT\nx-ms-version:2014-02-14\n/devstoreaccount1/devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos\ncomp:properties

Since the content is empty, the application is sending 0 as the content length while the Azurite is marking it as an empty string when constructing the string to sign. The rest portion of the string to sign is the same.

This seems to be a special case when the content is empty. The older version of Azurite and the legacy storage emulator and actual azure blob service seem to be handling it gracefully.

DebugLog from azurite 3.x: debug.log

In the above Azurite logs, we can see the RequestHeader has marked the content-length as 0 which seems to be ignored while creating the string to sign:

RequestHeaders:{"accept":"application/xml","accept-charset":"UTF-8","content-type":"","x-ms-version":"2014-02-14","user-agent":"Azure-Storage/2.0.0 (JavaJRE 1.8.0_311; Windows10 10.0)","x-ms-client-request-id":"3ebb0d3e-cbaf-4fa9-8cd4-5c06ec66c592","x-ms-date":"Wed, 23 Feb 2022 04:25:33 GMT","authorization":"SharedKey devstoreaccount1:BHoKqQc0r/jhNYZjLGps7+bilDRNfhpAcY/UJwCO4hE=","host":"127.0.0.1:10000","connection":"keep-alive","content-length":"0"}

Looks like what Azurite is doing is actually the documented behaviour.

// When using version 2015-02-21 or later, if Content-Length is zero, then
// set the Content-Length part of the StringToSign to an empty string.
// https://docs.microsoft.com/en-us/rest/api/storageservices/authenticate-with-shared-key
if (headerName === HeaderConstants.CONTENT_LENGTH && value === "0") {
  return "";
}

@pimehr Thanks for the investigation! From you investigation result and the doc, this looks is caused by a breaking change of StringToSign from API version 2014-02-14 to 2015-02-21 or later API version.

On 2014-02-14 and before, if Content-Length is zero, it will be "0" in StringToSign
On 2015-02-21 or later, if Content-Length is zero, it will be empty string in StringToSign

Azurite handle it with the way of 2015-02-21 and later, while you use API version 2014-02-14.

But there are also many other request in the debug log from you has "content-length":"0", but the content length is empty string in StringTosign, and signature matches. So it looks not all request with API version 2014-02-14 will has Content-Length as "0" in StringToSign.

We will need time to investigate more on how to fix it. However this is on a very old API version. So before we fix it, to work around this issue, do you mind to change to a later version of SDK, with a later API version.

I checked the debug logs again which I had attached. The behaviour seems to be consistent.

The other messages where we see "content-length":"0" seems to be the response messages (with "x-ms-version":"2021-02-12") to various requests sent from the application. One instance below:

2022-02-10T08:51:34.224Z fa6df80c-c95f-4cc9-8421-b4f799769c9e info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA== RequestHeaders:{"accept":"application/xml","accept-charset":"UTF-8","content-type":"","x-ms-version":"2014-02-14","user-agent":"Azure-Storage/2.0.0 (JavaJRE 1.8.0_311; Windows10 10.0)","x-ms-client-request-id":"8eed4ab0-05e9-4917-a202-b39c1aea1e9d","x-ms-date":"Thu, 10 Feb 2022 08:51:34 GMT","authorization":"SharedKey devstoreaccount1:2At1pM4+fgxQegQuIEWOi6QB0/aPJ/+xd6v172pgiHA=","host":"127.0.0.1:10000","connection":"keep-alive"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1 2022-02-10T08:51:34.225Z fa6df80c-c95f-4cc9-8421-b4f799769c9e info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:8eed4ab0-05e9-4917-a202-b39c1aea1e9d\nx-ms-date:Thu, 10 Feb 2022 08:51:34 GMT\nx-ms-version:2014-02-14\n/devstoreaccount1/devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==" 2022-02-10T08:51:34.225Z fa6df80c-c95f-4cc9-8421-b4f799769c9e info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"8eed4ab0-05e9-4917-a202-b39c1aea1e9d","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2014-02-14"} 2022-02-10T08:51:34.226Z fa6df80c-c95f-4cc9-8421-b4f799769c9e info: EndMiddleware: End response. TotalTimeInMS=2 StatusCode=200 StatusMessage=undefined Headers={"server":"Azurite-Blob/3.15.0","last-modified":"Thu, 10 Feb 2022 08:51:34 GMT","x-ms-creation-time":"Thu, 10 Feb 2022 08:51:34 GMT","x-ms-meta-hdi_isfolder":"true","x-ms-meta-hdi_permission":"{\"owner\":\"pimehr\",\"group\":\"supergroup\",\"permissions\":\"rwxr-xr-x\"}","x-ms-blob-type":"BlockBlob","x-ms-lease-state":"available","x-ms-lease-status":"unlocked","content-length":"0","content-type":"application/octet-stream","etag":"\"0x220BFC6DE3EE8C0\"","x-ms-client-request-id":"8eed4ab0-05e9-4917-a202-b39c1aea1e9d","x-ms-request-id":"fa6df80c-c95f-4cc9-8421-b4f799769c9e","x-ms-version":"2021-02-12","date":"Thu, 10 Feb 2022 08:51:34 GMT","accept-ranges":"bytes","x-ms-server-encrypted":"true","x-ms-access-tier":"Hot","x-ms-access-tier-inferred":"true"}

The application SDK sends "content-length" only for the PUT messages. When it had a non-zero value, we do not see any authorization problem. When it was sending empty content with "content-length" as 0, we see the authorization issues.

However this is on a very old API version. So before we fix it, to work around this issue, do you mind to change to a later version of SDK, with a later API version. I'm not sure how feasible will that be as of now since the application is in production for long time and this problem is only occurring when we are trying to use emulator to write the test cases.

@pimehr

Thanks for the clarify!

However, I have tested with .net SDK with same API version "2014-02-14", on API "Blob_GetProperties" (there's also the same API in your debug log). Although we both don't have "content-length" in the request, .net SDK signature will fail the validation on current Azurite. When I add content length as "0" in the StringToSign in Azurite, it will pass validation. So it looks in .net SDK, content length will be taken as "0" even if it's not in request on API version "2014-02-14". But on the request you send, when the "Blob_GetProperties" request don't have "content-length", it looks your SDK will just take is as "" in the StringToSign and pass validation.

So it looks different SDK has different behavior on StringToSign on "content-length" with API version "2014-02-14". We might still need more time to see how to make it work. Or do you have any idea?

For upgrade to new SDK, the 2014-02-14 is really old, upgrade it you can not only work around this issue, but also get the new feature and enhancement on storage side for new API version.

Besides that

Debug log when send "Blob_GetProperties" request with .net SDK on API version "2014-02-14"

2022-02-23T09:41:50.693Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85 RequestHeaders:{"host":"127.0.0.1:10000","user-agent":"WA-Storage/4.0.0 (.NET CLR 6.0.2; Win32NT 10.0.19044.0)","x-ms-version":"2014-02-14","x-ms-client-request-id":"78056464-840a-481a-bde4-9fc532d06bf2","x-ms-date":"Wed, 23 Feb 2022 09:41:50 GMT","authorization":"SharedKey devstoreaccount1:R30ISwz1vwJwM8AH5Nr6JYueIwZv8SP/FSE2ja/gqAU=","connection":"Keep-Alive"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-02-23T09:41:50.694Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=sparkconnectortests Blob=dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85
2022-02-23T09:41:50.694Z f93ff5d6-2d18-4a85-9282-fdb711670d78 verbose: DispatchMiddleware: Dispatching request...
2022-02-23T09:41:50.695Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-02-23T09:41:50.696Z f93ff5d6-2d18-4a85-9282-fdb711670d78 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-02-23T09:41:50.697Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-02-23T09:41:50.697Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-02-23T09:41:50.697Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: sparkconnectortests, blob: dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85
2022-02-23T09:41:50.697Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container sparkconnectortests
2022-02-23T09:41:50.697Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-02-23T09:42:06.810Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:78056464-840a-481a-bde4-9fc532d06bf2\nx-ms-date:Wed, 23 Feb 2022 09:41:50 GMT\nx-ms-version:2014-02-14\n/devstoreaccount1/devstoreaccount1/sparkconnectortests/dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85"
2022-02-23T09:42:06.810Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:vb/89ibrsAYfo1puLqK4x36eZq/vtMQaXImdVeaCIbY=
2022-02-23T09:42:06.810Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: BlobSharedKeyAuthenticator:validate() Validation failed.
2022-02-23T09:42:06.811Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: AccountSASAuthenticator:validate() Start validation against account Shared Access Signature pattern.
2022-02-23T09:42:06.811Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: AccountSASAuthenticator:validate() Getting account properties...
2022-02-23T09:42:06.811Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: AccountSASAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: sparkconnectortests, blob: dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85
2022-02-23T09:42:06.811Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: AccountSASAuthenticator:validate() Got account properties successfully.
2022-02-23T09:42:06.811Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: AccountSASAuthenticator:validate() Retrieved signature from URL parameter sig: undefined
2022-02-23T09:42:06.811Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: AccountSASAuthenticator:validate() Failed to get valid account SAS values from request.
2022-02-23T09:42:06.812Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: BlobSASAuthenticator:validate() Start validation against blob service Shared Access Signature pattern.
2022-02-23T09:42:06.812Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: BlobSASAuthenticator:validate() Getting account properties...
2022-02-23T09:42:06.812Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: BlobSASAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: sparkconnectortests, blob: dummyaccount/AgAAAA==/AgAAAIUFBKE=.Cosmos/PartitionId=ff11b509-7bd9-4234-aeac-4f5f4e134c85
2022-02-23T09:42:06.812Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: BlobSASAuthenticator:validate() Got account properties successfully.
2022-02-23T09:42:06.812Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: BlobSASAuthenticator:validate() Retrieved signature from URL parameter sig: undefined
2022-02-23T09:42:06.812Z f93ff5d6-2d18-4a85-9282-fdb711670d78 debug: BlobSASAuthenticator:validate() No signature found in request. Skip blob service SAS validation.
2022-02-23T09:42:06.813Z f93ff5d6-2d18-4a85-9282-fdb711670d78 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-02-23T09:42:06.813Z f93ff5d6-2d18-4a85-9282-fdb711670d78 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":"AuthorizationFailure","x-ms-request-id":"f93ff5d6-2d18-4a85-9282-fdb711670d78"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>AuthorizationFailure</Code>\n  <Message>Server failed to authenticate the request. Make sure the value of the Authorization header is formed correctly including the signature.\nRequestId:f93ff5d6-2d18-4a85-9282-fdb711670d78\nTime:2022-02-23T09:42:06.813Z</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 Function.getAuthorizationFailure (D:\\code\\azurite\\src\\blob\\errors\\StorageErrorFactory.ts:400:12)\n    at D:\\code\\azurite\\src\\blob\\middlewares\\AuthenticationMiddlewareFactory.ts:25:35\n    at processTicksAndRejections (node:internal/process/task_queues:96:5)"
2022-02-23T09:42:06.813Z f93ff5d6-2d18-4a85-9282-fdb711670d78 error: ErrorMiddleware: Set HTTP code: 403
2022-02-23T09:42:06.814Z f93ff5d6-2d18-4a85-9282-fdb711670d78 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.
2022-02-23T09:42:06.814Z f93ff5d6-2d18-4a85-9282-fdb711670d78 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=AuthorizationFailure
2022-02-23T09:42:06.814Z f93ff5d6-2d18-4a85-9282-fdb711670d78 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=f93ff5d6-2d18-4a85-9282-fdb711670d78
2022-02-23T09:42:06.815Z f93ff5d6-2d18-4a85-9282-fdb711670d78 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>AuthorizationFailure</Code>\n  <Message>Server failed to authenticate the request. Make sure the value of the Authorization header is formed correctly including the signature.\nRequestId:f93ff5d6-2d18-4a85-9282-fdb711670d78\nTime:2022-02-23T09:42:06.813Z</Message>\n</Error>"
2022-02-23T09:42:06.815Z f93ff5d6-2d18-4a85-9282-fdb711670d78 info: EndMiddleware: End response. TotalTimeInMS=16122 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-Blob/3.16.0","x-ms-error-code":"AuthorizationFailure","x-ms-request-id":"f93ff5d6-2d18-4a85-9282-fdb711670d78"}

Azure / Azurite