Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Table transaction rollback leaves duplicate entities #1230

Closed
joelverhagen opened this issue Dec 19, 2021 · 2 comments
Closed

Table transaction rollback leaves duplicate entities #1230

joelverhagen opened this issue Dec 19, 2021 · 2 comments
Assignees
@edwin-huber

Comments

@joelverhagen
Copy link
Contributor

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

table

Which version of the Azurite was used?

Locally running version of #1157

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

Git clone

What's the Node.js version?

16.13.0

What problem was encountered?

When a transaction is rolled back, it seems that at least sometimes a duplicate entity is left in the data store. Meaning there is more than one entity in LokiJS JSON data files that have the same partition key and row key.

Steps to reproduce the issue?

using Azure;
using Azure.Data.Tables;

var tableClient = new TableServiceClient("UseDevelopmentStorage=true");
var table = tableClient.GetTableClient("table0");
table.Delete();
table.Create();
table.AddEntity(new TableEntity("PK", "RK1"));
try
{
    table.SubmitTransaction(new[]
    {
        new TableTransactionAction(TableTransactionActionType.UpdateReplace, new TableEntity("PK", "RK1"), new ETag("W/\"datetime'2015-01-01T23%3A14%3A33.4980000Z'\"")),
    });
}
catch (TableTransactionFailedException)
{
    Console.WriteLine("Failed as expected.");
}
foreach (var entity in table.Query<TableEntity>(x => x.PartitionKey == "PK"))
{
    Console.WriteLine(entity.PartitionKey + " " + entity.RowKey);
}

This outputs:

Failed as expected.
PK RK1
PK RK1

2021-12-19T00:12:34.531Z 	 info: Azurite Blob service is starting on 127.0.0.1:10000
2021-12-19T00:12:34.533Z 	 info: AccountDataStore:init() Refresh accounts from environment variable AZURITE_ACCOUNTS with value undefined
2021-12-19T00:12:34.533Z 	 info: AccountDataStore:init() Fallback to default emulator account devstoreaccount1.
2021-12-19T00:12:34.574Z 	 info: BlobGCManager:start() Starting BlobGCManager. Set status to Initializing.
2021-12-19T00:12:34.574Z 	 info: BlobGCManager:start() Trigger mark and sweep loop. Set status to Running.
2021-12-19T00:12:34.575Z 	 info: BlobGCManager:markSweepLoop() Start next mark and sweep.
2021-12-19T00:12:34.575Z 	 info: BlobGCManager:markSweep() Get all extents.
2021-12-19T00:12:34.576Z 	 info: BlobGCManager:start() BlobGCManager successfully started.
2021-12-19T00:12:34.590Z 	 info: BlobGCManager:markSweep() Got 0 extents.
2021-12-19T00:12:34.591Z 	 info: BlobGCManager:markSweep() Get referred extents.
2021-12-19T00:12:34.591Z 	 info: BlobGCManager:markSweep() Got referred extents, unreferenced extents count is 0.
2021-12-19T00:12:34.592Z 	 info: BlobGCManager:markSweepLoop() Mark and sweep finished, taken 17ms.
2021-12-19T00:12:34.592Z 	 info: BlobGCManager:markSweepLoop() Sleep for 600000ms.
2021-12-19T00:12:34.595Z 	 info: Azurite Blob service successfully listens on http://127.0.0.1:10000
2021-12-19T00:12:34.596Z 	 info: Azurite Queue service is starting on 127.0.0.1:10001
2021-12-19T00:12:34.596Z 	 info: AccountDataStore:init() Refresh accounts from environment variable AZURITE_ACCOUNTS with value undefined
2021-12-19T00:12:34.597Z 	 info: AccountDataStore:init() Fallback to default emulator account devstoreaccount1.
2021-12-19T00:12:34.620Z 	 info: QueueGCManager:start() Starting QueueGCManager, set status to Initializing
2021-12-19T00:12:34.621Z 	 info: QueueGCManager:start() Trigger mark and sweep loop, set status to Running.
2021-12-19T00:12:34.621Z 	 info: QueueGCManager:markSweepLoop() Start new mark and sweep.
2021-12-19T00:12:34.622Z 	 info: QueueGCManger:markSweep() Get all extents.
2021-12-19T00:12:34.622Z 	 info: QueueGCManager:start() QueueGCManager successfully started.
2021-12-19T00:12:34.622Z 	 info: QueueGCManager:marksweep() Get 0 extents.
2021-12-19T00:12:34.622Z 	 info: QueueGCManager:markSweep() Get referred extents, then remove from allExtents.
2021-12-19T00:12:34.623Z 	 info: QueueGCManager:markSweep() Got referred extents, unreferenced extents count is 0.
2021-12-19T00:12:34.623Z 	 info: QueueGCManager:markSweepLoop() Mark and sweep finished, take 2ms.
2021-12-19T00:12:34.623Z 	 info: QueueGCManager:markSweepLoop() Sleep for 60000
2021-12-19T00:12:34.624Z 	 info: Azurite Queue service successfully listens on http://127.0.0.1:10001
2021-12-19T00:12:34.625Z 	 info: Azurite Table service is starting on 127.0.0.1:10002
2021-12-19T00:12:34.625Z 	 info: AccountDataStore:init() Refresh accounts from environment variable AZURITE_ACCOUNTS with value undefined
2021-12-19T00:12:34.626Z 	 info: AccountDataStore:init() Fallback to default emulator account devstoreaccount1.
2021-12-19T00:12:34.668Z 	 info: Azurite Table service successfully listens on http://127.0.0.1:10002
2021-12-19T00:12:37.520Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: TableStorageContextMiddleware: RequestMethod=DELETE RequestURL=http://127.0.0.1/devstoreaccount1/Tables('table0') RequestHeaders:{"host":"127.0.0.1:10002","x-ms-version":"2019-02-02","accept":"application/json","x-ms-client-request-id":"fdf5482b-e85a-48c3-8944-c49552412a88","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Data.Tables/12.3.0 (.NET 6.0.0-rtm.21522.10; Microsoft Windows 10.0.22000)","x-ms-date":"Sun, 19 Dec 2021 00:12:37 GMT","authorization":"SharedKeyLite devstoreaccount1:+0f9fIUG1/5zHKQswj6M2QntypgkDiCdH+Q74yMVspc="} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2021-12-19T00:12:37.521Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c debug: tableStorageContextMiddleware: Dispatch pattern string: /Tables('table0')
2021-12-19T00:12:37.521Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=table0
2021-12-19T00:12:37.521Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c verbose: DispatchMiddleware: Dispatching request...
2021-12-19T00:12:37.523Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: DispatchMiddleware: Operation=Table_Delete
2021-12-19T00:12:37.524Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2021-12-19T00:12:37.524Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2021-12-19T00:12:37.525Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: TableSharedKeyLiteAuthenticator:validate() [STRING TO SIGN]:"Sun, 19 Dec 2021 00:12:37 GMT\n/devstoreaccount1/devstoreaccount1/Tables('table0')"
2021-12-19T00:12:37.526Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: TableSharedKeyLiteAuthenticator:validate() Calculated authentication header based on key1: SharedKeyLite devstoreaccount1:+0f9fIUG1/5zHKQswj6M2QntypgkDiCdH+Q74yMVspc=
2021-12-19T00:12:37.526Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: TableSharedKeyLiteAuthenticator:validate() Signature 1 matched.
2021-12-19T00:12:37.527Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c verbose: DeserializerMiddleware: Start deserializing...
2021-12-19T00:12:37.529Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: HandlerMiddleware: DeserializedParameters={"version":"2019-02-02","options":{"requestId":"fdf5482b-e85a-48c3-8944-c49552412a88"}}
2021-12-19T00:12:37.533Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c verbose: SerializerMiddleware: Start serializing...
2021-12-19T00:12:37.535Z c52a1569-e9bb-4bae-b3c9-ed42b9f5399c info: EndMiddleware: End response. TotalTimeInMS=14 StatusCode=204 StatusMessage=undefined Headers={"server":"Azurite-Table/3.15.0","content-type":"application/json;odata=minimalmetadata","x-ms-client-request-id":"fdf5482b-e85a-48c3-8944-c49552412a88","x-ms-request-id":"c52a1569-e9bb-4bae-b3c9-ed42b9f5399c","x-ms-version":"2021-02-12","date":"Sun, 19 Dec 2021 00:12:37 GMT"}
2021-12-19T00:12:37.558Z bfb661d0-9077-4a29-8368-805b89466237 info: TableStorageContextMiddleware: RequestMethod=POST RequestURL=http://127.0.0.1/devstoreaccount1/Tables?$format=application%2Fjson%3Bodata%3Dminimalmetadata RequestHeaders:{"host":"127.0.0.1:10002","x-ms-version":"2019-02-02","dataserviceversion":"3.0","accept":"application/json;odata=minimalmetadata","x-ms-client-request-id":"91c78784-011e-404a-812b-859482710bea","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Data.Tables/12.3.0 (.NET 6.0.0-rtm.21522.10; Microsoft Windows 10.0.22000)","x-ms-date":"Sun, 19 Dec 2021 00:12:37 GMT","authorization":"SharedKeyLite devstoreaccount1:RIDCWUE7d8axSR1lHXS5cK47NG3bbjTvpufV7cQ9FGE=","content-type":"application/json;odata=nometadata","content-length":"22"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2021-12-19T00:12:37.559Z bfb661d0-9077-4a29-8368-805b89466237 debug: tableStorageContextMiddleware: Dispatch pattern string: /Tables
2021-12-19T00:12:37.559Z bfb661d0-9077-4a29-8368-805b89466237 info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=undefined
2021-12-19T00:12:37.559Z bfb661d0-9077-4a29-8368-805b89466237 verbose: DispatchMiddleware: Dispatching request...
2021-12-19T00:12:37.559Z bfb661d0-9077-4a29-8368-805b89466237 info: DispatchMiddleware: Operation=Table_Create
2021-12-19T00:12:37.559Z bfb661d0-9077-4a29-8368-805b89466237 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2021-12-19T00:12:37.559Z bfb661d0-9077-4a29-8368-805b89466237 info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2021-12-19T00:12:37.560Z bfb661d0-9077-4a29-8368-805b89466237 info: TableSharedKeyLiteAuthenticator:validate() [STRING TO SIGN]:"Sun, 19 Dec 2021 00:12:37 GMT\n/devstoreaccount1/devstoreaccount1/Tables"
2021-12-19T00:12:37.560Z bfb661d0-9077-4a29-8368-805b89466237 info: TableSharedKeyLiteAuthenticator:validate() Calculated authentication header based on key1: SharedKeyLite devstoreaccount1:RIDCWUE7d8axSR1lHXS5cK47NG3bbjTvpufV7cQ9FGE=
2021-12-19T00:12:37.560Z bfb661d0-9077-4a29-8368-805b89466237 info: TableSharedKeyLiteAuthenticator:validate() Signature 1 matched.
2021-12-19T00:12:37.561Z bfb661d0-9077-4a29-8368-805b89466237 verbose: DeserializerMiddleware: Start deserializing...
2021-12-19T00:12:37.562Z bfb661d0-9077-4a29-8368-805b89466237 debug: deserialize(): Raw request body string is (removed all empty characters) {"TableName":"table0"}
2021-12-19T00:12:37.563Z bfb661d0-9077-4a29-8368-805b89466237 info: HandlerMiddleware: DeserializedParameters={"options":{"queryOptions":{"format":"application/json;odata=minimalmetadata"},"requestId":"91c78784-011e-404a-812b-859482710bea","dataServiceVersion":"3.0"},"version":"2019-02-02","tableProperties":{"tableName":"table0"},"body":"ReadableStream"}
2021-12-19T00:12:37.565Z bfb661d0-9077-4a29-8368-805b89466237 verbose: SerializerMiddleware: Start serializing...
2021-12-19T00:12:37.566Z bfb661d0-9077-4a29-8368-805b89466237 debug: Serializer: Raw response body string is {"odata.metadata":"http://127.0.0.1:10002/devstoreaccount1/$metadata#Tables/@Element","TableName":"table0"}
2021-12-19T00:12:37.566Z bfb661d0-9077-4a29-8368-805b89466237 info: Serializer: Start returning stream body.
2021-12-19T00:12:37.566Z bfb661d0-9077-4a29-8368-805b89466237 info: EndMiddleware: End response. TotalTimeInMS=8 StatusCode=201 StatusMessage=Created Headers={"server":"Azurite-Table/3.15.0","content-type":"application/json;odata=minimalmetadata","x-ms-client-request-id":"91c78784-011e-404a-812b-859482710bea","x-ms-request-id":"bfb661d0-9077-4a29-8368-805b89466237","x-ms-version":"2021-02-12","date":"Sun, 19 Dec 2021 00:12:37 GMT","preference-applied":"return-content"}
2021-12-19T00:12:37.600Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: TableStorageContextMiddleware: RequestMethod=POST RequestURL=http://127.0.0.1/devstoreaccount1/table0?$format=application%2Fjson%3Bodata%3Dminimalmetadata RequestHeaders:{"host":"127.0.0.1:10002","x-ms-version":"2019-02-02","dataserviceversion":"3.0","prefer":"return-no-content","accept":"application/json;odata=minimalmetadata","x-ms-client-request-id":"6157117f-8e60-456a-a7c1-37d67643af7b","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Data.Tables/12.3.0 (.NET 6.0.0-rtm.21522.10; Microsoft Windows 10.0.22000)","x-ms-date":"Sun, 19 Dec 2021 00:12:37 GMT","authorization":"SharedKeyLite devstoreaccount1:Pp3jFr66kNfU4/FUfUe20QwAmQ6PHVq19C2uInVqp/A=","content-type":"application/json;odata=nometadata","content-length":"36"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2021-12-19T00:12:37.600Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b debug: tableStorageContextMiddleware: Dispatch pattern string: /table0
2021-12-19T00:12:37.600Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=table0
2021-12-19T00:12:37.600Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b verbose: DispatchMiddleware: Dispatching request...
2021-12-19T00:12:37.600Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: DispatchMiddleware: Operation=Table_InsertEntity
2021-12-19T00:12:37.600Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2021-12-19T00:12:37.600Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2021-12-19T00:12:37.601Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: TableSharedKeyLiteAuthenticator:validate() [STRING TO SIGN]:"Sun, 19 Dec 2021 00:12:37 GMT\n/devstoreaccount1/devstoreaccount1/table0"
2021-12-19T00:12:37.601Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: TableSharedKeyLiteAuthenticator:validate() Calculated authentication header based on key1: SharedKeyLite devstoreaccount1:Pp3jFr66kNfU4/FUfUe20QwAmQ6PHVq19C2uInVqp/A=
2021-12-19T00:12:37.601Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: TableSharedKeyLiteAuthenticator:validate() Signature 1 matched.
2021-12-19T00:12:37.601Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b verbose: DeserializerMiddleware: Start deserializing...
2021-12-19T00:12:37.602Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b debug: deserialize(): Raw request body string is (removed all empty characters) {"PartitionKey":"PK","RowKey":"RK1"}
2021-12-19T00:12:37.603Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: HandlerMiddleware: DeserializedParameters={"options":{"queryOptions":{"format":"application/json;odata=minimalmetadata"},"requestId":"6157117f-8e60-456a-a7c1-37d67643af7b","dataServiceVersion":"3.0","responsePreference":"return-no-content","tableEntityProperties":{"PartitionKey":"PK","RowKey":"RK1"}},"version":"2019-02-02","body":"ReadableStream"}
2021-12-19T00:12:37.604Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b verbose: SerializerMiddleware: Start serializing...
2021-12-19T00:12:37.605Z d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b info: EndMiddleware: End response. TotalTimeInMS=6 StatusCode=204 StatusMessage=undefined Headers={"server":"Azurite-Table/3.15.0","content-type":"application/json;odata=minimalmetadata","x-ms-client-request-id":"6157117f-8e60-456a-a7c1-37d67643af7b","x-ms-request-id":"d1ab0fb9-46e3-4fd5-af55-441a1cf6da8b","x-ms-version":"2021-02-12","date":"Sun, 19 Dec 2021 00:12:37 GMT","etag":"W/\"datetime'2021-12-19T00%3A12%3A37.5990000Z'\"","preference-applied":"return-no-content"}
2021-12-19T00:12:37.628Z 4b50e32b-dc34-4020-97b4-824660f78747 info: TableStorageContextMiddleware: RequestMethod=POST RequestURL=http://127.0.0.1/devstoreaccount1/$batch RequestHeaders:{"host":"127.0.0.1:10002","x-ms-version":"2019-02-02","dataserviceversion":"3.0","accept":"application/json","x-ms-client-request-id":"6f8f1d53-b935-40b2-8b0c-9ab37b487a3b","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Data.Tables/12.3.0 (.NET 6.0.0-rtm.21522.10; Microsoft Windows 10.0.22000)","x-ms-date":"Sun, 19 Dec 2021 00:12:37 GMT","authorization":"SharedKeyLite devstoreaccount1:y0eVGyTT35XRJ/H/vqIIhW8t22MQH8LVsGWk+7gBMX8=","content-type":"multipart/mixed; boundary=batch_7947ba54-26fd-420b-b666-9b1d043b981f","content-length":"727"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2021-12-19T00:12:37.628Z 4b50e32b-dc34-4020-97b4-824660f78747 debug: tableStorageContextMiddleware: Dispatch pattern string: /$batch
2021-12-19T00:12:37.628Z 4b50e32b-dc34-4020-97b4-824660f78747 info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=$batch
2021-12-19T00:12:37.628Z 4b50e32b-dc34-4020-97b4-824660f78747 verbose: DispatchMiddleware: Dispatching request...
2021-12-19T00:12:37.629Z 4b50e32b-dc34-4020-97b4-824660f78747 info: DispatchMiddleware: Operation=Table_Batch
2021-12-19T00:12:37.629Z 4b50e32b-dc34-4020-97b4-824660f78747 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2021-12-19T00:12:37.629Z 4b50e32b-dc34-4020-97b4-824660f78747 info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2021-12-19T00:12:37.629Z 4b50e32b-dc34-4020-97b4-824660f78747 info: TableSharedKeyLiteAuthenticator:validate() [STRING TO SIGN]:"Sun, 19 Dec 2021 00:12:37 GMT\n/devstoreaccount1/devstoreaccount1/$batch"
2021-12-19T00:12:37.629Z 4b50e32b-dc34-4020-97b4-824660f78747 info: TableSharedKeyLiteAuthenticator:validate() Calculated authentication header based on key1: SharedKeyLite devstoreaccount1:y0eVGyTT35XRJ/H/vqIIhW8t22MQH8LVsGWk+7gBMX8=
2021-12-19T00:12:37.629Z 4b50e32b-dc34-4020-97b4-824660f78747 info: TableSharedKeyLiteAuthenticator:validate() Signature 1 matched.
2021-12-19T00:12:37.629Z 4b50e32b-dc34-4020-97b4-824660f78747 verbose: DeserializerMiddleware: Start deserializing...
2021-12-19T00:12:37.629Z 4b50e32b-dc34-4020-97b4-824660f78747 info: HandlerMiddleware: DeserializedParameters={"version":"2019-02-02","options":{"requestId":"6f8f1d53-b935-40b2-8b0c-9ab37b487a3b","dataServiceVersion":"3.0"},"multipartContentType":"multipart/mixed; boundary=batch_7947ba54-26fd-420b-b666-9b1d043b981f","contentLength":727,"body":"ReadableStream"}
2021-12-19T00:12:37.631Z 4b50e32b-dc34-4020-97b4-824660f78747 debug: TableHandler:batch() Raw request string is "--batch_7947ba54-26fd-420b-b666-9b1d043b981f\r\nContent-Type: multipart/mixed; boundary=changeset_96f5539b-4d43-4914-8a4e-0d925c42bff2\r\n\r\n--changeset_96f5539b-4d43-4914-8a4e-0d925c42bff2\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nPUT http://127.0.0.1:10002/devstoreaccount1/table0(PartitionKey='PK',RowKey='RK1')?$format=application%2Fjson%3Bodata%3Dminimalmetadata HTTP/1.1\r\nHost: 127.0.0.1\r\nx-ms-version: 2019-02-02\r\nDataServiceVersion: 3.0\r\nIf-Match: W/\"datetime'2015-01-01T23%3A14%3A33.4980000Z'\"\r\nAccept: application/json\r\nContent-Type: application/json\r\n\r\n{\"PartitionKey\":\"PK\",\"RowKey\":\"RK1\"}\r\n--changeset_96f5539b-4d43-4914-8a4e-0d925c42bff2--\r\n\r\n--batch_7947ba54-26fd-420b-b666-9b1d043b981f--\r\n"
2021-12-19T00:12:37.635Z 4b50e32b-dc34-4020-97b4-824660f78747 debug: TableHandler:batch() Raw response string is "--batchresponse_7947ba54-26fd-420b-b666-9b1d043b981f\r\nContent-Type: multipart/mixed; boundary=changesetresponse_96f5539b-4d43-4914-8a4e-0d925c42bff2\r\n\r\n--changesetresponse_96f5539b-4d43-4914-8a4e-0d925c42bff2\r\nContent-Type: application/http\r\nContent-Transfer-Encoding: binary\r\n\r\nHTTP/1.1 412 STATUS_CODE_NOT_IMPLEMENTED\r\nContent-ID: 1\r\nDataServiceVersion: 3.0;\r\nContent-Type: application/json;odata=minimalmetadata;charset=utf-8\r\n\r\n{\"odata.error\":{\"code\":\"UpdateConditionNotSatisfied\",\"message\":{\"lang\":\"en-US\",\"value\":\"The update condition specified in the request was not satisfied.\\nRequestId:4b50e32b-dc34-4020-97b4-824660f78747\\nTime:2021-12-19T00:12:37.634Z\"}}}\r\n--changesetresponse_96f5539b-4d43-4914-8a4e-0d925c42bff2--\r\n--batchresponse_7947ba54-26fd-420b-b666-9b1d043b981f--\r\n"
2021-12-19T00:12:37.635Z 4b50e32b-dc34-4020-97b4-824660f78747 verbose: SerializerMiddleware: Start serializing...
2021-12-19T00:12:37.636Z 4b50e32b-dc34-4020-97b4-824660f78747 info: Serializer: Start returning stream body.
2021-12-19T00:12:37.639Z 4b50e32b-dc34-4020-97b4-824660f78747 info: EndMiddleware: End response. TotalTimeInMS=12 StatusCode=202 StatusMessage=Accepted Headers={"server":"Azurite-Table/3.15.0","content-type":"multipart/mixed; boundary=batchresponse_7947ba54-26fd-420b-b666-9b1d043b981f","x-ms-request-id":"4b50e32b-dc34-4020-97b4-824660f78747","x-ms-version":"2021-02-12","date":"Sun, 19 Dec 2021 00:12:37 GMT"}
2021-12-19T00:12:37.713Z 3abc1650-64fd-4757-b49e-894929ad143a info: TableStorageContextMiddleware: RequestMethod=GET RequestURL=http://127.0.0.1/devstoreaccount1/table0()?$format=application%2Fjson%3Bodata%3Dminimalmetadata&$filter=PartitionKey%20eq%20%27PK%27 RequestHeaders:{"host":"127.0.0.1:10002","x-ms-version":"2019-02-02","dataserviceversion":"3.0","accept":"application/json;odata=minimalmetadata","x-ms-client-request-id":"851caedd-42c5-425f-b384-895144561590","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Data.Tables/12.3.0 (.NET 6.0.0-rtm.21522.10; Microsoft Windows 10.0.22000)","x-ms-date":"Sun, 19 Dec 2021 00:12:37 GMT","authorization":"SharedKeyLite devstoreaccount1:Tsf26cmb+WfkSUxc+5BlWYfHAED9T5AR1Yhhbkc1L14="} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2021-12-19T00:12:37.714Z 3abc1650-64fd-4757-b49e-894929ad143a debug: tableStorageContextMiddleware: Dispatch pattern string: /table0()
2021-12-19T00:12:37.714Z 3abc1650-64fd-4757-b49e-894929ad143a info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=table0
2021-12-19T00:12:37.714Z 3abc1650-64fd-4757-b49e-894929ad143a verbose: DispatchMiddleware: Dispatching request...
2021-12-19T00:12:37.714Z 3abc1650-64fd-4757-b49e-894929ad143a info: DispatchMiddleware: Operation=Table_QueryEntities
2021-12-19T00:12:37.714Z 3abc1650-64fd-4757-b49e-894929ad143a verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2021-12-19T00:12:37.714Z 3abc1650-64fd-4757-b49e-894929ad143a info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2021-12-19T00:12:37.714Z 3abc1650-64fd-4757-b49e-894929ad143a info: TableSharedKeyLiteAuthenticator:validate() [STRING TO SIGN]:"Sun, 19 Dec 2021 00:12:37 GMT\n/devstoreaccount1/devstoreaccount1/table0()"
2021-12-19T00:12:37.715Z 3abc1650-64fd-4757-b49e-894929ad143a info: TableSharedKeyLiteAuthenticator:validate() Calculated authentication header based on key1: SharedKeyLite devstoreaccount1:Tsf26cmb+WfkSUxc+5BlWYfHAED9T5AR1Yhhbkc1L14=
2021-12-19T00:12:37.715Z 3abc1650-64fd-4757-b49e-894929ad143a info: TableSharedKeyLiteAuthenticator:validate() Signature 1 matched.
2021-12-19T00:12:37.715Z 3abc1650-64fd-4757-b49e-894929ad143a verbose: DeserializerMiddleware: Start deserializing...
2021-12-19T00:12:37.715Z 3abc1650-64fd-4757-b49e-894929ad143a info: HandlerMiddleware: DeserializedParameters={"options":{"queryOptions":{"format":"application/json;odata=minimalmetadata","filter":"PartitionKey eq 'PK'"},"requestId":"851caedd-42c5-425f-b384-895144561590","dataServiceVersion":"3.0"},"version":"2019-02-02"}
2021-12-19T00:12:37.718Z 3abc1650-64fd-4757-b49e-894929ad143a debug: TableHandler:queryEntities() Raw response string is "{\"odata.metadata\":\"http://127.0.0.1:10002/devstoreaccount1/$metadata#Tables/@Element\",\"value\":[{\"odata.etag\":\"W/\\\"datetime'2021-12-19T00%3A12%3A37.5990000Z'\\\"\",\"PartitionKey\":\"PK\",\"RowKey\":\"RK1\",\"Timestamp@odata.type\":\"Edm.DateTime\",\"Timestamp\":\"2021-12-19T00:12:37.5990000Z\"},{\"odata.etag\":\"W/\\\"datetime'2021-12-19T00%3A12%3A37.5990000Z'\\\"\",\"PartitionKey\":\"PK\",\"RowKey\":\"RK1\",\"Timestamp@odata.type\":\"Edm.DateTime\",\"Timestamp\":\"2021-12-19T00:12:37.5990000Z\"}]}"
2021-12-19T00:12:37.719Z 3abc1650-64fd-4757-b49e-894929ad143a verbose: SerializerMiddleware: Start serializing...
2021-12-19T00:12:37.719Z 3abc1650-64fd-4757-b49e-894929ad143a info: Serializer: Start returning stream body.
2021-12-19T00:12:37.722Z 3abc1650-64fd-4757-b49e-894929ad143a info: EndMiddleware: End response. TotalTimeInMS=9 StatusCode=200 StatusMessage=OK Headers={"server":"Azurite-Table/3.15.0","content-type":"application/json;odata=minimalmetadata","x-ms-client-request-id":"851caedd-42c5-425f-b384-895144561590","x-ms-request-id":"3abc1650-64fd-4757-b49e-894929ad143a","x-ms-version":"2021-02-12","date":"Sun, 19 Dec 2021 00:12:37 GMT"}
2021-12-19T00:12:40.826Z 	 info: Azurite Blob service is closing...
2021-12-19T00:12:40.827Z 	 info: Azurite Queue service is closing...
2021-12-19T00:12:40.827Z 	 info: Azurite Table service is closing...
2021-12-19T00:12:40.831Z 	 info: BlobGCManager:close() Start closing BlobGCManager. Set status to Closing.
2021-12-19T00:12:40.831Z 	 info: QueueGCManager:close() Start closing QueueGCManager, set status to Closing.
2021-12-19T00:12:40.831Z 	 info: BlobGCManager:start() Mark and sweep loop is closed.
2021-12-19T00:12:40.832Z 	 info: BlobGCManager:close() BlobGCManager successfully closed. Set status to Closed.
2021-12-19T00:12:40.832Z 	 info: QueueGCManager:start() Mark and sweep loop is closed.
2021-12-19T00:12:40.832Z 	 info: QueueGCManager:close() QueueGCManager successfully closed, set status to Closed.
2021-12-19T00:12:40.832Z 	 info: Azurite Table service successfully closed
2021-12-19T00:12:40.833Z 	 info: Azurite Blob service successfully closed
2021-12-19T00:12:40.833Z 	 info: Azurite Queue service successfully closed

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?
@joelverhagen
Copy link
Contributor Author

The fix appears to be:

diff --git a/src/table/persistence/LokiTableMetadataStore.ts b/src/table/persistence/LokiTableMetadataStore.ts
index fd3849d..b0c6c15 100644
--- a/src/table/persistence/LokiTableMetadataStore.ts
+++ b/src/table/persistence/LokiTableMetadataStore.ts
@@ -1155,7 +1155,13 @@ export default class LokiTableMetadataStore implements ITableMetadataStore {
             lastModifiedTime: entity.lastModifiedTime,
             eTag: entity.eTag
           };
-          // lokijs applies this insert as an upsert
+          const existing = tableBatchCollection.findOne({
+            PartitionKey: entity.PartitionKey,
+            RowKey: entity.RowKey,
+          })
+          if (existing) {
+            tableBatchCollection.remove(existing);
+          }
           tableBatchCollection.insert(copiedEntity);
         }

@joelverhagen joelverhagen mentioned this issue Dec 19, 2021
Closed
23 tasks
@edwin-huber
Copy link
Collaborator

Thanks this change has been committed to #1157

edwin-huber added a commit to edwin-huber/Azurite that referenced this issue Jan 18, 2022
@edwin-huber
fixes Azure#1230
07a35bf
@edwin-huber edwin-huber self-assigned this Feb 14, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@edwin-huber edwin-huber

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@joelverhagen @edwin-huber