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.

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

Table Storage fails querying for empty partition key #790

Closed
joelverhagen opened this issue May 19, 2021 · 3 comments · Fixed by #807
Closed

Table Storage fails querying for empty partition key #790

joelverhagen opened this issue May 19, 2021 · 3 comments · Fixed by #807
Assignees
Labels
bug Something isn't working NewArch Tracking issues for NewArch table-storage Relating to Azurite table storage implementation

Comments

@joelverhagen
Copy link
Contributor

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

table

Which version of the Azurite was used?

azurite@3.12.0

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

npm

What's the Node.js version?

v12.18.3

What problem was encountered?

Table queries for empty string partition key fail with this exception:

Unhandled exception. Azure.RequestFailedException: The query condition specified in the request is invalid.
RequestId:3abe68fd-60cb-40c1-9cf8-c1af9e947d41
Time:2021-05-19T16:50:57.616Z
Status: 400 (Bad Request)
ErrorCode: InvalidInput

Content:
{"odata.error":{"code":"InvalidInput","message":{"lang":"en-US","value":"The query condition specified in the request is invalid.\nRequestId:3abe68fd-60cb-40c1-9cf8-c1af9e947d41\nTime:2021-05-19T16:50:57.616Z"}}}

Headers:
Server: Azurite-Table/3.12.0
x-ms-error-code: REDACTED
x-ms-request-id: 3abe68fd-60cb-40c1-9cf8-c1af9e947d41
x-ms-version: REDACTED
Date: Wed, 19 May 2021 16:50:57 GMT
Connection: keep-alive
Transfer-Encoding: chunked
Content-Type: application/json; odata=minimalmetadata; streaming=true; charset=utf-8

Steps to reproduce the issue?

using Azure.Data.Tables;
using System.Threading.Tasks;

namespace ConsoleApp1
{
    class Program
    {
        static async Task Main(string[] args)
        {
            var tableServiceClient = new TableServiceClient("UseDevelopmentStorage=true");
            var tableClient = tableServiceClient.GetTableClient("test");
            await tableClient.CreateIfNotExistsAsync();
            await tableClient.QueryAsync<TableEntity>(x => x.PartitionKey == "").GetAsyncEnumerator().MoveNextAsync();
        }
    }
}
2021-05-19T16:51:48.023Z 	 info: Azurite Blob service is starting on 127.0.0.1:10000
2021-05-19T16:51:48.024Z 	 info: AccountDataStore:init() Refresh accounts from environment variable AZURITE_ACCOUNTS with value undefined
2021-05-19T16:51:48.024Z 	 info: AccountDataStore:init() Fallback to default emulator account devstoreaccount1.
2021-05-19T16:51:48.049Z 	 info: BlobGCManager:start() Starting BlobGCManager. Set status to Initializing.
2021-05-19T16:51:48.049Z 	 info: BlobGCManager:start() Trigger mark and sweep loop. Set status to Running.
2021-05-19T16:51:48.050Z 	 info: BlobGCManager:markSweepLoop() Start next mark and sweep.
2021-05-19T16:51:48.050Z 	 info: BlobGCManager:markSweep() Get all extents.
2021-05-19T16:51:48.050Z 	 info: BlobGCManager:start() BlobGCManager successfully started.
2021-05-19T16:51:48.062Z 	 info: BlobGCManager:markSweep() Got 0 extents.
2021-05-19T16:51:48.063Z 	 info: BlobGCManager:markSweep() Get referred extents.
2021-05-19T16:51:48.063Z 	 info: BlobGCManager:markSweep() Got referred extents, unreferenced extents count is 0.
2021-05-19T16:51:48.063Z 	 info: BlobGCManager:markSweepLoop() Mark and sweep finished, taken 13ms.
2021-05-19T16:51:48.063Z 	 info: BlobGCManager:markSweepLoop() Sleep for 600000ms.
2021-05-19T16:51:48.066Z 	 info: Azurite Blob service successfully listens on http://127.0.0.1:10000
2021-05-19T16:51:48.067Z 	 info: Azurite Queue service is starting on 127.0.0.1:10001
2021-05-19T16:51:48.067Z 	 info: AccountDataStore:init() Refresh accounts from environment variable AZURITE_ACCOUNTS with value undefined
2021-05-19T16:51:48.067Z 	 info: AccountDataStore:init() Fallback to default emulator account devstoreaccount1.
2021-05-19T16:51:48.096Z 	 info: QueueGCManager:start() Starting QueueGCManager, set status to Initializing
2021-05-19T16:51:48.096Z 	 info: QueueGCManager:start() Trigger mark and sweep loop, set status to Running.
2021-05-19T16:51:48.096Z 	 info: QueueGCManager:markSweepLoop() Start new mark and sweep.
2021-05-19T16:51:48.097Z 	 info: QueueGCManger:markSweep() Get all extents.
2021-05-19T16:51:48.097Z 	 info: QueueGCManager:start() QueueGCManager successfully started.
2021-05-19T16:51:48.097Z 	 info: QueueGCManager:marksweep() Get 0 extents.
2021-05-19T16:51:48.097Z 	 info: QueueGCManager:markSweep() Get referred extents, then remove from allExtents.
2021-05-19T16:51:48.097Z 	 info: QueueGCManager:markSweep() Got referred extents, unreferenced extents count is 0.
2021-05-19T16:51:48.097Z 	 info: QueueGCManager:markSweepLoop() Mark and sweep finished, take 0ms.
2021-05-19T16:51:48.097Z 	 info: QueueGCManager:markSweepLoop() Sleep for 60000
2021-05-19T16:51:48.098Z 	 info: Azurite Queue service successfully listens on http://127.0.0.1:10001
2021-05-19T16:51:48.099Z 	 info: Azurite Table service is starting on 127.0.0.1:10002
2021-05-19T16:51:48.099Z 	 info: AccountDataStore:init() Refresh accounts from environment variable AZURITE_ACCOUNTS with value undefined
2021-05-19T16:51:48.099Z 	 info: AccountDataStore:init() Fallback to default emulator account devstoreaccount1.
2021-05-19T16:51:48.112Z 	 info: Azurite Table service successfully listens on http://127.0.0.1:10002
2021-05-19T16:51:50.899Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 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":"1dce5d2e-4b23-48c8-ac75-7da82751c2e1","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Data.Tables/12.0.0-beta.8 (.NET 5.0.6; Microsoft Windows 10.0.19043)","x-ms-date":"Wed, 19 May 2021 16:51:50 GMT","authorization":"SharedKeyLite devstoreaccount1:gw7laeNdEq0fjiWkneXQHqR3A+ixo4OaG9RuU8Y6s4c=","content-type":"application/json;odata=nometadata","content-length":"20"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2021-05-19T16:51:50.899Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 debug: tableStorageContextMiddleware: Dispatch pattern string: /Tables
2021-05-19T16:51:50.899Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=undefined
2021-05-19T16:51:50.899Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 verbose: DispatchMiddleware: Dispatching request...
2021-05-19T16:51:50.901Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: DispatchMiddleware: Operation=Table_Create
2021-05-19T16:51:50.901Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2021-05-19T16:51:50.901Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2021-05-19T16:51:50.902Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: TableSharedKeyLiteAuthenticator:validate() [STRING TO SIGN]:"Wed, 19 May 2021 16:51:50 GMT\n/devstoreaccount1/devstoreaccount1/Tables"
2021-05-19T16:51:50.902Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: TableSharedKeyLiteAuthenticator:validate() Calculated authentication header based on key1: SharedKeyLite devstoreaccount1:gw7laeNdEq0fjiWkneXQHqR3A+ixo4OaG9RuU8Y6s4c=
2021-05-19T16:51:50.902Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: TableSharedKeyLiteAuthenticator:validate() Signature 1 matched.
2021-05-19T16:51:50.903Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 verbose: DeserializerMiddleware: Start deserializing...
2021-05-19T16:51:50.905Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 debug: deserialize(): Raw request body string is (removed all empty characters) {"TableName":"test"}
2021-05-19T16:51:50.906Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: HandlerMiddleware: DeserializedParameters={"options":{"queryOptions":{"format":"application/json;odata=minimalmetadata"},"requestId":"1dce5d2e-4b23-48c8-ac75-7da82751c2e1","dataServiceVersion":"3.0"},"version":"2019-02-02","tableProperties":{"tableName":"test"},"body":"ReadableStream"}
2021-05-19T16:51:50.907Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 verbose: SerializerMiddleware: Start serializing...
2021-05-19T16:51:50.908Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 debug: Serializer: Raw response body string is {"odata.metadata":"http://127.0.0.1:10002/devstoreaccount1/$metadata#Tables/@Element","TableName":"test"}
2021-05-19T16:51:50.908Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: Serializer: Start returning stream body.
2021-05-19T16:51:50.909Z 5f6d63d1-915f-4dcc-b65c-bace938a1513 info: EndMiddleware: End response. TotalTimeInMS=11 StatusCode=201 StatusMessage=Created Headers={"server":"Azurite-Table/3.12.0","content-type":"application/json;odata=minimalmetadata","x-ms-client-request-id":"1dce5d2e-4b23-48c8-ac75-7da82751c2e1","x-ms-request-id":"5f6d63d1-915f-4dcc-b65c-bace938a1513","x-ms-version":"2020-06-12","date":"Wed, 19 May 2021 16:51:50 GMT","preference-applied":"return-content"}
2021-05-19T16:51:50.946Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: TableStorageContextMiddleware: RequestMethod=GET RequestURL=http://127.0.0.1/devstoreaccount1/test()?$format=application%2Fjson%3Bodata%3Dminimalmetadata&$filter=PartitionKey%20eq%20%27%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":"798145a7-5e5f-41ef-aafe-cbe68ed9a8f9","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Data.Tables/12.0.0-beta.8 (.NET 5.0.6; Microsoft Windows 10.0.19043)","x-ms-date":"Wed, 19 May 2021 16:51:50 GMT","authorization":"SharedKeyLite devstoreaccount1:0hf9M7D06+bgvex+V333OlXZyWRgMG0HLS55k2zords="} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2021-05-19T16:51:50.946Z bcc82040-ce96-430b-bfe5-05bcd827d69a debug: tableStorageContextMiddleware: Dispatch pattern string: /test()
2021-05-19T16:51:50.947Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: tableStorageContextMiddleware: Account=devstoreaccount1 tableName=test
2021-05-19T16:51:50.947Z bcc82040-ce96-430b-bfe5-05bcd827d69a verbose: DispatchMiddleware: Dispatching request...
2021-05-19T16:51:50.947Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: DispatchMiddleware: Operation=Table_QueryEntities
2021-05-19T16:51:50.947Z bcc82040-ce96-430b-bfe5-05bcd827d69a verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2021-05-19T16:51:50.947Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: TableSharedKeyLiteAuthenticator:validate() Start validation against account shared key authentication.
2021-05-19T16:51:50.947Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: TableSharedKeyLiteAuthenticator:validate() [STRING TO SIGN]:"Wed, 19 May 2021 16:51:50 GMT\n/devstoreaccount1/devstoreaccount1/test()"
2021-05-19T16:51:50.947Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: TableSharedKeyLiteAuthenticator:validate() Calculated authentication header based on key1: SharedKeyLite devstoreaccount1:0hf9M7D06+bgvex+V333OlXZyWRgMG0HLS55k2zords=
2021-05-19T16:51:50.947Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: TableSharedKeyLiteAuthenticator:validate() Signature 1 matched.
2021-05-19T16:51:50.948Z bcc82040-ce96-430b-bfe5-05bcd827d69a verbose: DeserializerMiddleware: Start deserializing...
2021-05-19T16:51:50.948Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: HandlerMiddleware: DeserializedParameters={"options":{"queryOptions":{"format":"application/json;odata=minimalmetadata","filter":"PartitionKey eq ''"},"requestId":"798145a7-5e5f-41ef-aafe-cbe68ed9a8f9","dataServiceVersion":"3.0"},"version":"2019-02-02"}
2021-05-19T16:51:50.950Z bcc82040-ce96-430b-bfe5-05bcd827d69a error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2021-05-19T16:51:50.950Z bcc82040-ce96-430b-bfe5-05bcd827d69a error: ErrorMiddleware: ErrorName=StorageError ErrorMessage="The query condition specified in the request is invalid."  ErrorHTTPStatusCode=400 ErrorHTTPStatusMessage=undefined ErrorHTTPHeaders={"x-ms-error-code":"InvalidInput","x-ms-request-id":"bcc82040-ce96-430b-bfe5-05bcd827d69a","x-ms-version":"2020-06-12"} ErrorHTTPBody="{\"odata.error\":{\"code\":\"InvalidInput\",\"message\":{\"lang\":\"en-US\",\"value\":\"The query condition specified in the request is invalid.\\nRequestId:bcc82040-ce96-430b-bfe5-05bcd827d69a\\nTime:2021-05-19T16:51:50.950Z\"}}}" ErrorStack="\"StorageError: The query condition specified in the request is invalid.\\n    at Function.getQueryConditionInvalid (C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\dist\\\\src\\\\table\\\\errors\\\\StorageErrorFactory.js:76:16)\\n    at LokiTableMetadataStore.queryTableEntities (C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\dist\\\\src\\\\table\\\\persistence\\\\LokiTableMetadataStore.js:329:49)\\n    at TableHandler.queryEntities (C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\dist\\\\src\\\\table\\\\handlers\\\\TableHandler.js:273:81)\\n    at C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\dist\\\\src\\\\table\\\\generated\\\\middleware\\\\HandlerMiddlewareFactory.js:58:18\\n    at C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\dist\\\\src\\\\table\\\\generated\\\\ExpressMiddlewareFactory.js:77:63\\n    at Layer.handle [as handle_request] (C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\node_modules\\\\express\\\\lib\\\\router\\\\layer.js:95:5)\\n    at trim_prefix (C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\node_modules\\\\express\\\\lib\\\\router\\\\index.js:317:13)\\n    at C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\node_modules\\\\express\\\\lib\\\\router\\\\index.js:284:7\\n    at Function.process_params (C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\node_modules\\\\express\\\\lib\\\\router\\\\index.js:335:12)\\n    at next (C:\\\\Users\\\\jver\\\\AppData\\\\Roaming\\\\npm\\\\node_modules\\\\azurite\\\\node_modules\\\\express\\\\lib\\\\router\\\\index.js:275:10)\""
2021-05-19T16:51:50.951Z bcc82040-ce96-430b-bfe5-05bcd827d69a error: ErrorMiddleware: Set HTTP code: 400
2021-05-19T16:51:50.951Z bcc82040-ce96-430b-bfe5-05bcd827d69a error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=InvalidInput
2021-05-19T16:51:50.951Z bcc82040-ce96-430b-bfe5-05bcd827d69a error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=bcc82040-ce96-430b-bfe5-05bcd827d69a
2021-05-19T16:51:50.951Z bcc82040-ce96-430b-bfe5-05bcd827d69a error: ErrorMiddleware: Set HTTP Header: x-ms-version=2020-06-12
2021-05-19T16:51:50.951Z bcc82040-ce96-430b-bfe5-05bcd827d69a error: ErrorMiddleware: Set content type: application/json;odata=minimalmetadata;streaming=true;charset=utf-8
2021-05-19T16:51:50.951Z bcc82040-ce96-430b-bfe5-05bcd827d69a error: ErrorMiddleware: Set HTTP body: "{\"odata.error\":{\"code\":\"InvalidInput\",\"message\":{\"lang\":\"en-US\",\"value\":\"The query condition specified in the request is invalid.\\nRequestId:bcc82040-ce96-430b-bfe5-05bcd827d69a\\nTime:2021-05-19T16:51:50.950Z\"}}}"
2021-05-19T16:51:50.951Z bcc82040-ce96-430b-bfe5-05bcd827d69a info: EndMiddleware: End response. TotalTimeInMS=5 StatusCode=400 StatusMessage=Bad Request Headers={"server":"Azurite-Table/3.12.0","x-ms-error-code":"InvalidInput","x-ms-request-id":"bcc82040-ce96-430b-bfe5-05bcd827d69a","x-ms-version":"2020-06-12","content-type":"application/json;odata=minimalmetadata;streaming=true;charset=utf-8"}
2021-05-19T16:51:54.677Z 	 info: Azurite Blob service is closing...
2021-05-19T16:51:54.677Z 	 info: Azurite Queue service is closing...
2021-05-19T16:51:54.678Z 	 info: Azurite Table service is closing...
2021-05-19T16:51:54.678Z 	 info: BlobGCManager:close() Start closing BlobGCManager. Set status to Closing.
2021-05-19T16:51:54.678Z 	 info: QueueGCManager:close() Start closing QueueGCManager, set status to Closing.
2021-05-19T16:51:54.679Z 	 info: BlobGCManager:start() Mark and sweep loop is closed.
2021-05-19T16:51:54.679Z 	 info: BlobGCManager:close() BlobGCManager successfully closed. Set status to Closed.
2021-05-19T16:51:54.679Z 	 info: QueueGCManager:start() Mark and sweep loop is closed.
2021-05-19T16:51:54.679Z 	 info: QueueGCManager:close() QueueGCManager successfully closed, set status to Closed.
2021-05-19T16:51:54.679Z 	 info: Azurite Table service successfully closed
2021-05-19T16:51:54.679Z 	 info: Azurite Blob service successfully closed
2021-05-19T16:51:54.679Z 	 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?

@edwin-huber edwin-huber self-assigned this May 21, 2021
@edwin-huber
Copy link
Collaborator

Hi,
I looked into this, and am able to repro, thanks for the sample!
We are working on fixing it.

@edwin-huber
Copy link
Collaborator

@CodeUnicornMartha
This is caused by generateQueryEntityWhereFunction
Line 665

Query is deserialized into the function as PartitionKey eq ''
We are expecting the quotes to be escaped, rather than there being an empty string.

.replace(/''/g, "@ESCAPEDQUOTE@")

@edwin-huber
Copy link
Collaborator

Fix in Review

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working NewArch Tracking issues for NewArch table-storage Relating to Azurite table storage implementation
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants