Azure / Azurite

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

UseDevelopmentStorage=true - Fails with 'The value for one of the HTTP headers is not in the correct format' #1476

Closed TimDaborn closed 2 years ago

TimDaborn commented 2 years ago

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

Blob

Which version of the Azurite was used?

3.14

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

Visual Studio - running Azure functions

What's the Node.js version?

N/A

What problem was encountered?

Cannot create a container - 'The value for one of the HTTP headers is not in the correct format' using the recommended "UseDevelopmentStorage=true" Connection. See https://docs.microsoft.com/en-us/azure/storage/common/storage-use-azurite?tabs=visual-studio#connection-strings

I can create an Azure table - but not a blob container.

Steps to reproduce the issue?

string endPoint = "UseDevelopmentStorage=true";

//This works with the Development endPoint
var serviceClient = new TableServiceClient(endPoint);
serviceClient.CreateTableIfNotExists("mytable");

var blobServiceClient = new BlobServiceClient(endPoint);

//This fails using the same endpoint - The value for one of the HTTP headers is not in the correct format
var containerClient = blobServiceClient.CreateBlobContainer("mycontainer");

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>"

Providing the log is not easy to do - given that I am relying on the Azure Core tools to run the environment and that defines the location of the log. This appears to be the relevant section from the log.

2022-05-04T13:51:02.100Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: BlobStorageContextMiddleware: RequestMethod=PUT RequestURL=http://127.0.0.1/devstoreaccount1/azure-webjobs-hosts/locks/timssurface2-2051300736/host?comp=lease RequestHeaders:{"host":"127.0.0.1:10000","x-ms-lease-action":"renew","x-ms-lease-id":"0000000000000000000000009A8DF540","x-ms-version":"2020-08-04","accept":"application/xml","x-ms-client-request-id":"3dbd6ed9-d43b-4353-8734-3454e47128a9","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Storage.Blobs/12.9.0 (.NET 6.0.3; Microsoft Windows 10.0.19043)","x-ms-date":"Wed, 04 May 2022 13:51:02 GMT","authorization":"SharedKey devstoreaccount1:hjbw0ANc4GDsyuSAUmdrjkpCxsF6caAx2s9x1zlBYlw=","content-length":"0"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1 2022-05-04T13:51:02.100Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=azure-webjobs-hosts Blob=locks/timssurface2-2051300736/host 2022-05-04T13:51:02.100Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 verbose: DispatchMiddleware: Dispatching request... 2022-05-04T13:51:02.101Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: DispatchMiddleware: Operation=Blob_RenewLease 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications. 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: PublicAccessAuthenticator:validate() Start validation against public access. 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 debug: PublicAccessAuthenticator:validate() Getting account properties... 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: azure-webjobs-hosts, blob: locks/timssurface2-2051300736/host 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container azure-webjobs-hosts 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication. 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"PUT\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:3dbd6ed9-d43b-4353-8734-3454e47128a9\nx-ms-date:Wed, 04 May 2022 13:51:02 GMT\nx-ms-lease-action:renew\nx-ms-lease-id:0000000000000000000000009A8DF540\nx-ms-return-client-request-id:true\nx-ms-version:2020-08-04\n/devstoreaccount1/devstoreaccount1/azure-webjobs-hosts/locks/timssurface2-2051300736/host\ncomp:lease" 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:hjbw0ANc4GDsyuSAUmdrjkpCxsF6caAx2s9x1zlBYlw= 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched. 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 verbose: DeserializerMiddleware: Start deserializing... 2022-05-04T13:51:02.102Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"3dbd6ed9-d43b-4353-8734-3454e47128a9","modifiedAccessConditions":{}},"comp":"lease","leaseId":"0000000000000000000000009A8DF540","version":"2020-08-04","action":"renew"} 2022-05-04T13:51:02.103Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 verbose: SerializerMiddleware: Start serializing... 2022-05-04T13:51:02.103Z 6d0c7665-974d-4a9d-a380-9daa9832ca83 info: EndMiddleware: End response. TotalTimeInMS=3 StatusCode=200 StatusMessage=undefined Headers={"server":"Azurite-Blob/3.14.1","etag":"\"0x1D83B825394DD80\"","last-modified":"Wed, 04 May 2022 13:49:14 GMT","x-ms-lease-id":"0000000000000000000000009A8DF540","x-ms-client-request-id":"3dbd6ed9-d43b-4353-8734-3454e47128a9","x-ms-request-id":"6d0c7665-974d-4a9d-a380-9daa9832ca83","x-ms-version":"2020-10-02","date":"Wed, 04 May 2022 13:51:02 GMT"} 2022-05-04T13:51:14.097Z fe90b32a-e5d5-40b9-867b-d210f60e131c info: BlobStorageContextMiddleware: RequestMethod=PUT RequestURL=http://127.0.0.1/devstoreaccount1/azure-webjobs-hosts/locks/timssurface2-2051300736/host?comp=lease RequestHeaders:{"host":"127.0.0.1:10000","x-ms-lease-action":"renew","x-ms-lease-id":"0000000000000000000000009A8DF540","x-ms-version":"2020-08-04","accept":"application/xml","x-ms-client-request-id":"ce9d0c06-7c9a-4047-b639-d3ee189047d1","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Storage.Blobs/12.9.0 (.NET 6.0.3; Microsoft Windows 10.0.19043)","x-ms-date":"Wed, 04 May 2022 13:51:14 GMT","authorization":"SharedKey devstoreaccount1:cRgHwGdl38BZS1LzyNX1tfqb660zdRIWbeyH9bFFQ/4=","content-length":"0"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1 2022-05-04T13:51:14.097Z fe90b32a-e5d5-40b9-867b-d210f60e131c info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=azure-webjobs-hosts Blob=locks/timssurface2-2051300736/host 2022-05-04T13:51:14.097Z fe90b32a-e5d5-40b9-867b-d210f60e131c verbose: DispatchMiddleware: Dispatching request... 2022-05-04T13:51:14.097Z fe90b32a-e5d5-40b9-867b-d210f60e131c info: DispatchMiddleware: Operation=Blob_RenewLease 2022-05-04T13:51:14.097Z fe90b32a-e5d5-40b9-867b-d210f60e131c verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications. 2022-05-04T13:51:14.097Z fe90b32a-e5d5-40b9-867b-d210f60e131c info: PublicAccessAuthenticator:validate() Start validation against public access. 2022-05-04T13:51:14.098Z fe90b32a-e5d5-40b9-867b-d210f60e131c debug: PublicAccessAuthenticator:validate() Getting account properties... 2022-05-04T13:51:14.098Z fe90b32a-e5d5-40b9-867b-d210f60e131c debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: azure-webjobs-hosts, blob: locks/timssurface2-2051300736/host 2022-05-04T13:51:14.098Z fe90b32a-e5d5-40b9-867b-d210f60e131c debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container azure-webjobs-hosts 2022-05-04T13:51:14.098Z fe90b32a-e5d5-40b9-867b-d210f60e131c info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication. 2022-05-04T13:51:14.098Z fe90b32a-e5d5-40b9-867b-d210f60e131c info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"PUT\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:ce9d0c06-7c9a-4047-b639-d3ee189047d1\nx-ms-date:Wed, 04 May 2022 13:51:14 GMT\nx-ms-lease-action:renew\nx-ms-lease-id:0000000000000000000000009A8DF540\nx-ms-return-client-request-id:true\nx-ms-version:2020-08-04\n/devstoreaccount1/devstoreaccount1/azure-webjobs-hosts/locks/timssurface2-2051300736/host\ncomp:lease"

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?

No - I have tried various connection strings.

blueww commented 2 years ago

@TimDaborn From the debug log we don't see the create container request, but only Blob_RenewLease request. We will need the debug log to investigate this issue. Please share the Azurite debug log for the failed create container reqest.

TimDaborn commented 2 years ago

Ok Found it

2022-05-05T08:34:32.920Z error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response 2022-05-05T08:34:32.920Z error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The value for one of the HTTP headers is not in the correct format. ErrorHTTPStatusCode=400 ErrorHTTPStatusMessage=The value for one of the HTTP headers is not in the correct format. ErrorHTTPHeaders={"x-ms-error-code":"InvalidHeaderValue","x-ms-request-id":"e4176e64-316a-4f15-86de-47734ef6da72"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n\n InvalidHeaderValue\n The value for one of the HTTP headers is not in the correct format.\nRequestId:e4176e64-316a-4f15-86de-47734ef6da72\nTime:2022-05-05T08:34:32.917Z\n x-ms-version\n 2021-06-08\n" ErrorStack="StorageError: The value for one of the HTTP headers is not in the correct format.\n at Function.getInvalidHeaderValue (C:\snapshot\_azure_azurite\dist\src\blob\errors\StorageErrorFactory.js:210:16)\n at Object.checkApiVersion (C:\snapshot\_azure_azurite\dist\src\blob\utils\utils.js:9:45)\n at blobStorageContextMiddleware (C:\snapshot\_azure_azurite\dist\src\blob\middlewares\blobStorageContext.middleware.js:33:21)\n at C:\snapshot\_azure_azurite\dist\src\blob\middlewares\blobStorageContext.middleware.js:14:16\n at Layer.handle [as handle_request] (C:\snapshot\_azure_azurite\node_modules\express\lib\router\layer.js:95:5)\n at trim_prefix (C:\snapshot\_azure_azurite\node_modules\express\lib\router\index.js:317:13)\n at C:\snapshot\_azure_azurite\node_modules\express\lib\router\index.js:284:7\n at Function.process_params (C:\snapshot\_azure_azurite\node_modules\express\lib\router\index.js:335:12)\n at next (C:\snapshot\_azure_azurite\node_modules\express\lib\router\index.js:275:10)\n at logger (C:\snapshot\_azure_azurite\node_modules\morgan\index.js:144:5)" 2022-05-05T08:34:32.920Z error: ErrorMiddleware: Set HTTP code: 400 2022-05-05T08:34:32.920Z error: ErrorMiddleware: Set HTTP status message: The value for one of the HTTP headers is not in the correct format. 2022-05-05T08:34:32.920Z error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=InvalidHeaderValue 2022-05-05T08:34:32.920Z error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=e4176e64-316a-4f15-86de-47734ef6da72 2022-05-05T08:34:32.920Z error: ErrorMiddleware: Set content type: application/xml 2022-05-05T08:34:32.920Z error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n\n InvalidHeaderValue\n The value for one of the HTTP headers is not in the correct format.\nRequestId:e4176e64-316a-4f15-86de-47734ef6da72\nTime:2022-05-05T08:34:32.917Z\n x-ms-version\n 2021-06-08\n" 2022-05-05T08:34:32.920Z info: EndMiddleware: End response. TotalTimeInMS=undefined StatusCode=400 StatusMessage=The value for one of the HTTP headers is not in the correct format. Headers={"server":"Azurite-Blob/3.14.1","x-ms-error-code":"InvalidHeaderValue","x-ms-request-id":"e4176e64-316a-4f15-86de-47734ef6da72","content-type":"application/xml"} 2022-05-05T08:35:09.667Z info: AccountDataStore:init() Refresh accounts from environment variable AZURITE_ACCOUNTS with value undefined 2022-05-05T08:35:09.668Z info: AccountDataStore:init() Fallback to default emulator account devstoreaccount1. 2022-05-05T08:35:09.763Z info: AccountDataStore:init() Refresh accounts from environment variable AZURITE_ACCOUNTS with value undefined 2022-05-05T08:35:09.763Z info: AccountDataStore:init() Fallback to default emulator account devstoreaccount1.

blueww commented 2 years ago

@TimDaborn Would you please give the full debug log of the failed request? (You only give the part which report error, but not have the log when server receive the request.) We need to see the request Uri and all headers of the request (which is debug log) to investigate this issue.

TimDaborn commented 2 years ago

Ok I did not see anything else - but below is the complete log I took this morning.

For reference I am using Visual Studio. This morning I created a new log in my temp directory, replicated the error and then renamed the log. As you can see code above, there are 2 commands: CreateTableIfNotExists and CreateBlobContainer both using the "UseDevelopmentStorage=true" connection. For the first command I had not deleted the table before hand, hence the TableAlreadyExists message. For the 2nd command I can't see any additional messages from the server.

If I look at the service dependency output I see:

Ensuring Azure Functions Core Tools are up to date. This may take a few minutes... Azure Functions Core Tools are up to date. Api: C:\PROGRAM FILES\MICROSOFT VISUAL STUDIO\2022\COMMUNITY\COMMON7\IDE\EXTENSIONS\MICROSOFT\Azure Storage Emulator\azurite.exe --location "C:\Users\Tim\AppData\Local\Temp\Azurite" --debug "C:\Users\Tim\AppData\Local\Temp\Azurite\debug.log" Api: Azurite Blob service is starting at http://127.0.0.1:10000/ Api: Azurite Blob service is successfully listening at http://127.0.0.1:10000/ Api: Azurite Queue service is starting at http://127.0.0.1:10001/ Api: Azurite Queue service is successfully listening at http://127.0.0.1:10001/ Api: Azurite Table service is starting at http://127.0.0.1:10002/ Api: Azurite Table service is successfully listening at http://127.0.0.1:10002/

--Omitted content--

Api: 127.0.0.1 - - [05/May/2022:20:51:44 +0000] "POST /devstoreaccount1/Tables?$format=application%2Fjson%3Bodata%3Dminimalmetadata HTTP/1.1" 409 - Api: 127.0.0.1 - - [05/May/2022:20:51:44 +0000] "PUT /devstoreaccount1/mycontainer?restype=container HTTP/1.1" 400 -

Here is the log:

debug with Error.log

marios-siatis commented 2 years ago

I can confirm I am getting the same issue on version Azurite-Blob/3.14.3

blueww commented 2 years ago

@TimDaborn I tried to repro the issue with Azurite 3.14.3, by the same code in your repro steps (run the code twice). I use "Azure.Data.Tables 12.5.0" and "Azure.Storage.Blobs 12.9.0".

But the issue not repro on my side. The first create table and container both success. The second create table and container both return 409 as expected. The debug log attached. debug.log

From you debug log, I only see the error reported from Azurite, but not see the request that cause the error. As I can't repro the issue on my side, it's difficult for me to investigate this issue.

Could you share more details, espicially if you can give the request details that cause the error, it will help. Besides that, could you try if the issue can repro on latest Azurire 3.17.1 (you can install with npm, VS extension or docker).

TimDaborn commented 2 years ago

I am not sure what more details I can provide.

But I am also using "Azure.Data.Tables 12.5.0" but using the latest "Azure.Storage.Blobs 12.12.0".

The application is an Azure static Web App - so Azurite is started by Visual Studio when the component function project is opened. So, there is not much control over Azurite or its parameters.

Are there instructions on how to upgrade Azurite within Visual Studio? I can't see it as a Visual Studio component in the Installer.

Because if I install via NPM or Visual studio code - I suspect that won't affect the version that visual studio will run when starting the app.

Is Azurite updated as part of the regular Visual Studio updates that occur every 2-3 weeks? I assume it must be. Because I can wait a couple of weeks.

Otherwise looking around on the web, upgrading the visual studio version does not a trivial thing to do. From looking posts here and elsewhere I am not sure if anyone has done it successfully.

blueww commented 2 years ago

@TimDaborn

I get why you meet this error. It's because the "Azure.Storage.Blobs 12.12.0" use API version "2021-06-08" by default, which is still not supported by Azurite 3.14.x. (3.14.x support API version up to "2020-10-02") If you use latest Azurite 3.17.1, it won't have this issue.

If you can't upgrade azurite, there are 2 ways to workaround it:

  1. Start Azurite with parameter "--skipapiversioncheck", So Azurite won't report error when the API version is not supported
  2. Specific the API version with run the blob request with latest blob SDK, like :
// specify API version as 2020-10-02 when create blob service client, so all request send from it and it's child object will use this specific API version
var blobServiceClient = new BlobServiceClient(endPoint, new BlobClientOptions(BlobClientOptions.ServiceVersion.V2020_10_02));

 //This will success on azurite 3.14.x when API version is specified as above
 var containerClient = blobServiceClient.CreateBlobContainer("mycontainer");

For long term, I will discuss with Visual studio team to see if they can add "--skipapiversioncheck" in start Azurite in VS.

TimDaborn commented 2 years ago

Thank you - I did not know that Azurite was tightly bound to specific versions of the API. Am I right in thinking? Azure.Storage.Blobs 12.9.0 = Azurite 3.14 Azure.Storage.Blobs 12.10.0 = Azurite 3.15 Azure.Storage.Blobs 12.11.0 = Azurite 3.16 Azure.Storage.Blobs 12.12.0 = Azurite 3.17

Is this just for Storage or does this affect Queues and Tables?

Where is this documented?

TimDaborn commented 2 years ago

As for the long term – ideally if Azurite is installed automatically as part of Visual Studio, it should be upgraded as part of Visual Studio, either as part of the regular updates or as an extension.

Because of my previous bad experiences with NPM – my heart always sinks when I encounter something that has to be installed by NPM. I always prefer something that is simpler and does not come with so much baggage.

So, if I have to use NPM I really would appreciate detailed documentation on how to upgrade and avoid conflicts – beyond the simple installation commands.

For example:

I presume that you cannot have 2 different versions of Azurite running on the same machine at the same time?

Is the recommendation to install separately, or to overwrite the Visual studio version?

If the former, how do you stop Visual Studio from loading its version? If the later, what happens if Visual studio ever upgrades its version?

Can you share data between 2 versions? Is that advisable?

What. outside of directory contents, is installed/ shared between the 2 versions that might cause a conflict?

Is this a tried and trusted path – that has been rigorously tested?

How does all this affect Azure Storage Explorer?

marios-siatis commented 2 years ago

@blueww thanks. Seems to be solved at v3.17.1

blueww commented 2 years ago

@TimDaborn For the API version match, you can check Azurite change log and blob SDK change log, they both contain the information of the API version of the release. And Azurite support all API versions before the last supported API version. Following is the match as I see:

Azure.Storage.Blobs 12.9.0 = Azurite 3.13(2020-08-04) Azure.Storage.Blobs 12.10.0 = Azurite 3.14 (2020-10-02) Azurite 3.15 (2021-02-12) Azure.Storage.Blobs 12.11.0 = Azurite 3.16 (2021-04-10) Azure.Storage.Blobs 12.12.0 = Azurite 3.17 (2021-06-08)

This applies to blob/Queue/Table.

blueww commented 2 years ago

@TimDaborn

If you don't want to use npm, you can also try to run Azurite with VS Code extension or docker.

We can install 2 Azurite on same machine. But to start 2 Azurite instance on same time on same machine, they need to use different blobPort (default 10000), queuePort (default 10001), tablePort (default 10002) , to avoid the conflict on port.

TimDaborn commented 2 years ago

Ideally, I would just like to have one version of Azurite installed on my machine.

Having to track which version of Azurite goes with which API is a headache I can do without.

So, while I like the convenience of Visual Studio installing Azurite, I think there is an issue here is that the version of Azurite in Visual studio is not being updated when a new version is released. In addition, having no control over the start command is not helpful either.

I found this request under consideration in the Visual Studio Feedback: https://developercommunity.visualstudio.com/t/VS-2022-ships-outdated-Azurite-version/10026492

And this GitHub issue : https://github.com/MicrosoftDocs/azure-docs/issues/83901

@blueww

If you have any other suggestions to how or where I can raise this issue, please let me know.

Thanks.

blueww commented 2 years ago

@TimDaborn Following is the way to raise VS issue, as I get from VS team: https://docs.microsoft.com/en-us/visualstudio/ide/how-to-report-a-problem-with-visual-studio?view=vs-2022

TimDaborn commented 2 years ago

OK that is what I did - except there was one raised already, which I commented on and upvoted.

Thanks @blueww . I will now close this issue.

viktoreinars commented 2 years ago

For anyone else that is having this issue with a .NET based Azure Function: After updating Visual Studio the Azurite version was upgraded and everything worked.

dominikblazic commented 1 year ago

I have updated VS from version 17.2.1 to 17.4.2. and like @viktoreinars said everything worked.