Azure / Azurite

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

Batch update fails with internalServerError #1883

Open PrasantJillella opened 1 year ago

PrasantJillella commented 1 year ago

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

Table

Which version of the Azurite was used?

3.22.0

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

npm

What's the Node.js version?

v18.14.2

What problem was encountered?

Batch Update operation (tried with batch size of 3 and 60) to table storage fails with 500 "Internal Server Error" Class used for building tableClient = CloudTable, its name space: Microsoft.WindowsAzure.Storage.Table

Function invoked to perform the operation: this.table.ExecuteBatchAsync(batch,GetRequestOptions(operationType),operationContext,cancellationToken);

parameters values:

  1. TableBatchOperation batch: size 60 or 3, isReadOnly : false Values: 60 or 3 rows with each having PartitionKey, RowKey, TimeStamp,

Is there something to do with Batch Size and timeout at azurite? Checking since this does not fail in AzureTableStorage and Azure Storage Emulator.

Steps to reproduce the issue?

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:

2023-03-29T19:58:56.664Z b8935388-ceef-42ea-8467-cb06c7a18422 verbose: DeserializerMiddleware: Start deserializing...
2023-03-29T19:58:56.664Z b8935388-ceef-42ea-8467-cb06c7a18422 info: HandlerMiddleware: DeserializedParameters={"version":"2018-03-28","options":{"requestId":"99e5ad31-b826-4968-9430-3fb53adfee3f","dataServiceVersion":"3.0;"},"multipartContentType":"multipart/mixed; boundary=batch_4ae6d40e-e618-4a07-9187-25d9fe2934da","contentLength":27956,"body":"ReadableStream"}
2023-03-29T19:58:56.665Z b8935388-ceef-42ea-8467-cb06c7a18422 debug: TableHandler:batch() Raw request string is "--batch_4ae6d40e-e618-4a07-9187-25d9fe2934da\r\nContent-Type: multipart/mixed; boundary=changeset_eec6b123-335a-4fbd-ba71-b8511e4f3d97\r\n\r\n--changeset_eec6b123-335a-4fbd-ba71-b8511e4f3d97\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='0c917b01-b84b-48bf-bf5e-1e27e8a894c3') HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9986970Z'\"\r\n\r\n{}\r\n--changeset_eec6b123-335a-4fbd-ba71-b8511e4f3d97\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='88ae395d-ce0c-4d3d-afdb-cebfed30fb9b') HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9986987Z'\"\r\n\r\n{}\r\n--changeset_eec6b123-335a-4fbd-ba71-b8511e4f3d97\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='4c76d3fe-0c56-487e-bb14-63aca63bbec2') HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9986998Z'\"\r\n\r\n{}\r\n--changeset_eec6b123-335a-4fbd-ba71-b8511e4f3d97\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='b295bbf3-b147-4c60-a030-46d813bb7fe3') HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9987001Z'\"\r\n\r\n{}\r\n--changeset_eec6b123-335a-4fbd-ba71-b8511e4f3d97\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT 
..
..
..
so on upto 60 records.)

 HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9987145Z'\"\r\n\r\n{}\r\n--changeset_eec6b123-335a-4fbd-ba71-b8511e4f3d97--\r\n--batch_4ae6d40e-e618-4a07-9187-25d9fe2934da--\r\n"
2023-03-29T19:58:56.666Z b8935388-ceef-42ea-8467-cb06c7a18422 error: ErrorMiddleware: Received an error, fill error information to HTTP response
2023-03-29T19:58:56.666Z b8935388-ceef-42ea-8467-cb06c7a18422 error: ErrorMiddleware: ErrorName=Error ErrorMessage=Couldn't extract path from sub-Request:
 Content-Type: application/http
Content-Transfer-Encoding: binary

PUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='0c917b01-b84b-48bf-bf5e-1e27e8a894c3') HTTP/1.1
Accept: application/json;odata=minimalmetadata
Content-Type: application/json
DataServiceVersion: 3.0;
If-Match: W/"datetime'2023-03-29T19%3A10%3A38.9986970Z'"

{}
 ErrorStack="Error: Couldn't extract path from sub-Request:\n Content-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='0c917b01-b84b-48bf-bf5e-1e27e8a894c3') HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9986970Z'\"\r\n\r\n{}\r\n\n    at C:\\Users\\sjillella\\source\\Azurite\\dist\\src\\table\\batch\\TableBatchSerialization.js:71:23\n    at Array.map (<anonymous>)\n    at TableBatchSerialization.deserializeBatchRequest (C:\\Users\\sjillella\\source\\Azurite\\dist\\src\\table\\batch\\TableBatchSerialization.js:52:45)\n    at TableBatchOrchestrator.processBatchRequestAndSerializeResponse (C:\\Users\\sjillella\\source\\Azurite\\dist\\src\\table\\batch\\TableBatchOrchestrator.js:46:32)\n    at TableHandler.batch (C:\\Users\\sjillella\\source\\Azurite\\dist\\src\\table\\handlers\\TableHandler.js:498:50)\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)"
2023-03-29T19:58:56.666Z b8935388-ceef-42ea-8467-cb06c7a18422 error: ErrorMiddleware: Set HTTP code: 500
2023-03-29T19:58:56.666Z b8935388-ceef-42ea-8467-cb06c7a18422 info: EndMiddleware: End response. TotalTimeInMS=4 StatusCode=500 StatusMessage=undefined Headers={"server":"Azurite-Table/3.22.0"}
2023-03-29T19:59:09.559Z 916cf31c-9ede-4540-886c-fa74a097d113 info: TableStorageContextMiddleware: RequestMethod=POST RequestURL=http://127.0.0.1/devstoreaccount1/$batch RequestHeaders:{"host":"127.0.0.1:10002","accept-charset":"UTF-8","maxdataserviceversion":"3.0;NetFx","dataserviceversion":"3.0;","x-ms-client-request-id":"99e5ad31-b826-4968-9430-3fb53adfee3f","user-agent":"Azure-Storage/9.3.2 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Wed, 29 Mar 2023 19:59:09 GMT","authorization":"SharedKey devstoreaccount1:8FhGLJr9WYAxBMf3ioS3NVEal80V/w9uAUcZh3M/ibI=","content-length":"27956","content-type":"multipart/mixed; boundary=batch_1627bcfa-7bdf-453e-b432-681c501eaf02"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2023-03-29T19:59:09.559Z 916cf31c-9ede-4540-886c-fa74a097d113 debug: tableStorageContextMiddleware: Dispatch pattern string: /$batch
2023-03-29T19:59:09.559Z 916cf31c-9ede-4540-886c-fa74a097d113 info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=$batch
2023-03-29T19:59:09.559Z 916cf31c-9ede-4540-886c-fa74a097d113 verbose: DispatchMiddleware: Dispatching request...
2023-03-29T19:59:09.560Z 916cf31c-9ede-4540-886c-fa74a097d113 info: DispatchMiddleware: Operation=Table_Batch
2023-03-29T19:59:09.560Z 916cf31c-9ede-4540-886c-fa74a097d113 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2023-03-29T19:59:09.560Z 916cf31c-9ede-4540-886c-fa74a097d113 info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2023-03-29T19:59:09.560Z 916cf31c-9ede-4540-886c-fa74a097d113 info: TableSharedKeyLiteAuthenticator:validate() Request doesn't include valid authentication header. Skip SharedKeyLite authentication.
2023-03-29T19:59:09.560Z 916cf31c-9ede-4540-886c-fa74a097d113 info: TableSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2023-03-29T19:59:09.561Z 916cf31c-9ede-4540-886c-fa74a097d113 info: TableSharedKeyAuthenticator:validate() [STRING TO SIGN]:"POST\n\nmultipart/mixed; boundary=batch_1627bcfa-7bdf-453e-b432-681c501eaf02\nWed, 29 Mar 2023 19:59:09 GMT\n/devstoreaccount1/devstoreaccount1/$batch"
2023-03-29T19:59:09.561Z 916cf31c-9ede-4540-886c-fa74a097d113 info: TableSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:8FhGLJr9WYAxBMf3ioS3NVEal80V/w9uAUcZh3M/ibI=
2023-03-29T19:59:09.561Z 916cf31c-9ede-4540-886c-fa74a097d113 info: TableSharedKeyAuthenticator:validate() Signature 1 matched.
2023-03-29T19:59:09.561Z 916cf31c-9ede-4540-886c-fa74a097d113 verbose: DeserializerMiddleware: Start deserializing...
2023-03-29T19:59:09.561Z 916cf31c-9ede-4540-886c-fa74a097d113 info: HandlerMiddleware: DeserializedParameters={"version":"2018-03-28","options":{"requestId":"99e5ad31-b826-4968-9430-3fb53adfee3f","dataServiceVersion":"3.0;"},"multipartContentType":"multipart/mixed; boundary=batch_1627bcfa-7bdf-453e-b432-681c501eaf02","contentLength":27956,"body":"ReadableStream"}
2023-03-29T19:59:09.562Z 916cf31c-9ede-4540-886c-fa74a097d113 debug: TableHandler:batch() Raw request string is "--batch_1627bcfa-7bdf-453e-b432-681c501eaf02\r\nContent-Type: multipart/mixed; boundary=changeset_15c62bcd-623d-4952-9314-a41c283d2a95\r\n\r\n--changeset_15c62bcd-623d-4952-9314-a41c283d2a95\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='0c917b01-b84b-48bf-bf5e-1e27e8a894c3') HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9986970Z'\"\r\n\r\n{}\r\n--changeset_15c62bcd-623d-4952-9314-a41c283d2a95\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='88ae395d-ce0c-4d3d-afdb-cebfed30fb9b') HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9986987Z'\"\r\n\r\n{}\r\n--changeset_15c62bcd-623d-4952-9314-a41c283d2a95\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='4c76d3fe-0c56-487e-bb14-63aca63bbec2')

..
..
..
So on upto 60 records.

 HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9987144Z'\"\r\n\r\n{}\r\n--changeset_15c62bcd-623d-4952-9314-a41c283d2a95\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='dad0038b-092f-419a-b818-455f1d9f21ba') HTTP/1.1\r\nAccept: application/json;odata=minimalmetadata\r\nContent-Type: application/json\r\nDataServiceVersion: 3.0;\r\nIf-Match: W/\"datetime'2023-03-29T19%3A10%3A38.9987145Z'\"\r\n\r\n{}\r\n--changeset_15c62bcd-623d-4952-9314-a41c283d2a95--\r\n--batch_1627bcfa-7bdf-453e-b432-681c501eaf02--\r\n"
2023-03-29T19:59:09.562Z 916cf31c-9ede-4540-886c-fa74a097d113 error: ErrorMiddleware: Received an error, fill error information to HTTP response
2023-03-29T19:59:09.562Z 916cf31c-9ede-4540-886c-fa74a097d113 error: ErrorMiddleware: ErrorName=Error ErrorMessage=Couldn't extract path from sub-Request:
 Content-Type: application/http
Content-Transfer-Encoding: binary

PUT http://127.0.0.1:10002/devstoreaccount1/ArchiveStreamsTable(PartitionKey='077b857e-0bf1-46e8-be9d-e3e50080cd72',RowKey='0c917b01-b84b-48bf-bf5e-1e27e8a894c3') HTTP/1.1
Accept: application/json;odata=minimalmetadata
Content-Type: application/json
DataServiceVersion: 3.0;
If-Match: W/"datetime'2023-03-29T19%3A10%3A38.9986970Z'"

Have you found a mitigation/solution?

No

blueww commented 1 year ago

@PrasantJillella

We recent has a fix released for a similar issue in 3.23.0. Would you please upgrade Azurite, and try again?

PrasantJillella commented 1 year ago

Hi

Sure, I can check and get back. Thank you.

PrasantJillella commented 1 year ago

Hi, The issue is still happening in my case.

I think the ErrorMessage in the other ticket mentioned by you is: ErrorMessage=URI malformed ErrorStack="URIError: URI malformed\n at decodeURI (<anonymous>)\

The ErrorMessage that I see in my case is: ErrorMessage=Couldn't extract path from sub-Request: Content-Type: application/http Content-Transfer-Encoding: binary

blueww commented 1 year ago

@edwin-huber

Do you have any idea why the error happen? It looks the error is reported here: https://github.com/Azure/Azurite/blob/704e39b568faf1a80751bbb32683d2abae8396e2/src/table/batch/TableBatchSerialization.ts#L94

edwin-huber commented 1 year ago

It looks like it might be failing due to the empty JSON in the sub request.

edwin-huber commented 1 year ago

I would need to debug it to be 100% sure.

PrasantJillella commented 1 year ago

Hi

Checking to see if there was any update. Thank you.

tygore587 commented 1 year ago

We have the same issue in Version 3.23.0.

The following error happened:

2023-04-21T13:33:12.144Z 0039946d-f463-463c-879f-cf108d743a61 error: ErrorMiddleware: ErrorName=Error ErrorMessage=Couldn't extract path from sub-Request:
 Content-Type: application/http
Content-Transfer-Encoding: binary

MERGE http://127.0.0.1:10002/devstoreaccount1/Perm(PartitionKey='2',RowKey='View') HTTP/1.1
Accept: application/json;odata=minimalmetadata
Content-Type: application/json
DataServiceVersion: 3.0;

{}

We also only have a partiotion and row key in the entity, nothing else. So maybe the empty json is the problem here. @edwin-huber.

How is the progress at the moment for this issue?

PrasantJillella commented 1 year ago

oh ok, I am waiting for a fix as well.

PrasantJillella commented 1 year ago

Hi @edwin-huber

Checking to see if verifying and fixing the issue would take longer, Just want to review options with my team for unblocking our azurite migration task.

Thank you.

edwin-huber commented 11 months ago

I have a fix for this... will be done in the next PR from me

tomachristian commented 10 months ago

@edwin-huber any news on this? It continues to fail with "Couldn't extract path from sub-Request" for btch requests for us. We are using product-style URLs (we do not have the account name in the path) and it seems that it fails because BatchSerialization.extractPath expects that the account name is in the path, whereas for us it is not.

PS: I would be happy to help on this myself, but IDK how to get the information of whether a product-syle url or not in that function.

edwin-huber commented 10 months ago

This appears to be occurring because the JSON body is left empty in some SDKs.
I am currently unable to reproduce with the instructions above.
I was unable to find an SDK and code to replicate the issue to confirm that the fix works as intended.

Can someone share the code and framework / module / Package SDK version you are using to get this error? The following is not causing the issue: Windows.Azure.Storage 9.3.3

var batch = new TableBatchOperation();
batch.Insert(new TableEntity(pk,"rk1"));
batch.Insert(new TableEntity(pk, "rk2"));
batch.Insert(new TableEntity(pk, "rk3"));
tomachristian commented 10 months ago

I am using Orleans, but by looking at the code it does not at all seem that it is because of an/the empty JSON body. It is failing at this line: https://github.com/Azure/Azurite/blob/62ea623a79ba6860f49a30f66971b67edd5991c6/src/table/batch/TableBatchSerialization.ts#L80, my URL does not contain the account name in the path (am using production-style URLs) and that is why the implementation of extractPath https://github.com/Azure/Azurite/blob/62ea623a79ba6860f49a30f66971b67edd5991c6/src/table/batch/TableBatchSerialization.ts#L78C27-L78C38 is failing because of its incorrect implementation here: https://github.com/Azure/Azurite/blob/62ea623a79ba6860f49a30f66971b67edd5991c6/src/table/batch/BatchSerialization.ts#L76. You can see how the implementation assumes that for sub-requests in a batch, the path in the URL ALWAYS contains the account name. Am I missing something?

edwin-huber commented 10 months ago

This issue was opened for the error: Couldn't extract path from sub-Request. Which is caused as described above.

It appears that the error you are referencing is different: Couldn't extract path from URL in sub-Request. Could you open a separate issue for that (if there is not one already)?

tomachristian commented 10 months ago

Ahh, indeed. You are right, thank you! I will open a new issue.

PS: Created here https://github.com/Azure/Azurite/issues/2322, cc @edwin-huber 🙏