Azurite icon indicating copy to clipboard operation
Azurite copied to clipboard

Published 20 hours ago • verified publisher icon Azure

Batch update fails with internalServerError

Open PrasantJillella opened this issue 2 years ago • 16 comments

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

PrasantJillella avatar Mar 29 '23 20:03 PrasantJillella

@PrasantJillella

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

blueww avatar Mar 30 '23 05:03 blueww

Hi

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

PrasantJillella avatar Apr 03 '23 13:04 PrasantJillella

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

PrasantJillella avatar Apr 03 '23 14:04 PrasantJillella

@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

blueww avatar Apr 04 '23 07:04 blueww

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

edwin-huber avatar Apr 04 '23 07:04 edwin-huber

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

edwin-huber avatar Apr 04 '23 07:04 edwin-huber

Hi

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

PrasantJillella avatar Apr 09 '23 17:04 PrasantJillella

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?

tygore587 avatar Apr 21 '23 14:04 tygore587

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

PrasantJillella avatar Apr 24 '23 16:04 PrasantJillella

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.

PrasantJillella avatar May 01 '23 16:05 PrasantJillella

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

edwin-huber avatar Oct 20 '23 07:10 edwin-huber

@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.

tomachristian avatar Dec 09 '23 12:12 tomachristian

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

edwin-huber avatar Dec 11 '23 09:12 edwin-huber

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?

tomachristian avatar Dec 11 '23 09:12 tomachristian

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)?

edwin-huber avatar Dec 11 '23 09:12 edwin-huber

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 🙏

tomachristian avatar Dec 11 '23 09:12 tomachristian