Potential bug in `current` function implementation in the Cosmos package #24493

josegl · 2023-01-16T13:28:48Z

Package Name: Cosmos
Package Version: 3.17.2
Operating system: Linux
nodejs
- version: ^16
browser
- name/version:
typescript
- version:
Is the bug related to documentation in
- README.md
- source code documentation
- SDK API docs on https://docs.microsoft.com

Describe the bug
When the current function is executed, it reaches the FetchResultType.Exception case, so it will do this (line 2813):

fetchResult.error.headers = this._getAndResetActiveResponseHeaders();

But we have this exception raised:

TypeError: Cannot set properties of undefined (setting 'headers')
So I think that for some reason in fetchResult there is not error property set, and it fails to throw the actual error.

To Reproduce
We don't know how to reproduce this because we had this stack trace in our logs, so when we wanted to investigate what was going on, we found this thing, so we don't know was was the actual problem.

Expected behavior
To throw the expected error in order to check out what was actually the problem that triggered the error.
Screenshots

Additional context
This did not happen in local, but in a cloud environment in the Azure cloud.

The text was updated successfully, but these errors were encountered:

sajeetharan · 2023-01-20T10:23:50Z

@josegl Thanks for reporting the issue, can you provide more information on what operation you are trying to do? Also the complete stack trace of the exception.

josegl · 2023-01-26T08:01:52Z

@sajeetharan sorry that I did not update this sooner.
Here you have the stacktrace:

TypeError: Cannot set properties of undefined (setting 'headers')
    at DocumentProducer.current (/home/site/wwwroot/node_modules/@${ourProjectModules}/${OurModuleName}/node_modules/@azure/cosmos/dist/index.js:2813:47)
    at DocumentProducer.current (/home/site/wwwroot/node_modules/@${OurProjectModules}/${ourModuleName}/node_modules/@azure/cosmos/dist/index.js:2835:21)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async throttledFunc (/home/site/wwwroot/node_modules/@${ourProjectModules}/${ourModuleName}/node_modules/@azure/cosmos/dist/index.js:3280:67) {
  headers: { 'x-ms-request-charge': 0, 'x-ms-documentdb-query-metrics': {} }
}

The operation that we were trying to do was a query to one collection in one of our CosmosDB databases. This happens very deep in the network stack regarding AppInsights: (the actual name of the collections and db names are hidden under variable names)

Request hits our http endpoint
An Azure function is executed
Checking auth for the given token
InitialTime POST /dbs/${ourDb}-shared-throughput/colls/${collectionName}/docs
+1ms POST /dbs/${ourDb}-shared-throughput/colls/${collectionName}/docs
+4ms we have this extra info:

{
  "ticks": 5800,
  "metrics": {
    "retrievedDocumentCount": 0,
    "retrievedDocumentSize": 0,
    "outputDocumentCount": 0,
    "outputDocumentSize": 49,
    "indexHitDocumentCount": 0,
    "totalQueryExecutionTime": {
      "_ticks": 5800
    },
    "queryPreparationTimes": {
      "queryCompilationTime": {
        "_ticks": 1000
      },
      "logicalPlanBuildTime": {
        "_ticks": 300
      },
      "physicalPlanBuildTime": {
        "_ticks": 1200
      },
      "queryOptimizationTime": {
        "_ticks": 100
      }
    },
    "indexLookupTime": {
      "_ticks": 1100
    },
    "documentLoadTime": {
      "_ticks": 0
    },
    "vmExecutionTime": {
      "_ticks": 2000
    },
    "runtimeExecutionTimes": {
      "queryEngineExecutionTime": {
        "_ticks": 900
      },
      "systemFunctionExecutionTime": {
        "_ticks": 0
      },
      "userDefinedFunctionExecutionTime": {
        "_ticks": 0
      }
    },
    "documentWriteTime": {
      "_ticks": 0
    },
    "clientSideMetrics": {
      "requestCharge": 2.89
    }
  },
  "query": "\n    SELECT DISTINCT VALUE c[\"id\"] \n    FROM c  WHERE (c._type = (\"$DocumentType\")) AND (NOT (IS_DEFINED(c.removedAt))) AND (c.companyId = @companyId)    ",
  "parameters": [
    {
      "name": "@companyId",
      "value": "${companyId}"
    }
  ]
}

+1ms POST /dbs/${dbName}-shared-throughput/colls/${collectionName}/docs
+3ms POST /dbs/${dbName}-shared-throughput/colls/${collectionName}/docs
+1ms POST /dbs/${dbName}-shared-throughput/colls/${collectionName}/docs
+1ms the function prints this:

{"request":{"query":{"pageSize":"50","pageOffset":"0"},"body":{"fieldPath":"the.path.we.are.searching","searchText":"","includeTotal":true,"lang":"ourLang"}}}

+11 ms GET /dbs/${dbName}-shared-throughput/colls/${collectionName}/pkranges
+11 ms POST /dbs/${dbName}-shared-throughput/colls/${collectionName}/docs
+27ms we get the already mentioned stacktrace:

TypeError: Cannot set properties of undefined (setting 'headers')
    at DocumentProducer.current (/home/site/wwwroot/node_modules/@${ourProjectModules}/${OurModuleName}/node_modules/@azure/cosmos/dist/index.js:2813:47)
    at DocumentProducer.current (/home/site/wwwroot/node_modules/@${OurProjectModules}/${ourModuleName}/node_modules/@azure/cosmos/dist/index.js:2835:21)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async throttledFunc (/home/site/wwwroot/node_modules/@${ourProjectModules}/${ourModuleName}/node_modules/@azure/cosmos/dist/index.js:3280:67) {
  headers: { 'x-ms-request-charge': 0, 'x-ms-documentdb-query-metrics': {} }
}

charly22 · 2023-01-30T13:18:56Z

Hi @sajeetharan Was this info useful? Thanks for looking into this

charly22 · 2023-01-31T16:56:03Z

@xirzec would be possible for you to take a look at this? thank you very much

sajeetharan · 2023-01-31T16:59:55Z

@charly22 we are tracking this. @abkolant-MSFT @v1k1

josegl · 2023-02-07T12:16:09Z

@sajeetharan do you have any update on this?

sajeetharan · 2023-02-07T13:24:52Z

We just discussed on this, @amanrao23 will provide an update soon! is it blocking you on anything?

charly22 · 2023-02-07T14:31:02Z

@sajeetharan thanks for the update and sorry for our insistence

we're actually experiencing this issue in our production environment once in a while, so, blocking no, but affecting the reliability of our product yes.

amanrao23 · 2023-02-10T08:20:48Z

Hi, it would be helpful if you could provide us the following details to recreate this scenario.

Throughput configured for the container.
If possible, provide us some sample data that is present in the container.
Also, any other information that could help us reproduce this scenario.

charly22 · 2023-02-10T15:14:55Z

EDIT

The following information it's actually of not much relevancy. See please the next comment in the thread. Thanks

Throughput configured for the container

The throughput it's shared and configured to 2000 RU/S but according to our data we haven't reached the limit, in case you wonder

If possible, provide us some sample data that is present in the container.

This is one example of a document stored in that container that would have been found by the query we already sent you

{
    "id": "c3dd6734-9a5a-478b-84a9-69e13ff8f383",
    "requestIds": [],
    "quoteIds": [],
    "stn": "E9C19432C8304942B25EF353637C76DB",
    "tenantId": "b9c2f122-460e-40f4-9713-50897b97ed35",
    "userId": "fc6ddc67-3b59-431b-bfb3-ea2f936ea521",
    "orderDate": "2022-07-04T15:44:14.669Z",
    "comment": "",
    "orderExternalNo": "AB22-000567",
    "status": "confirmed",
    "companyId": "b2077619-4bfe-4790-9bfe-a042a3ad2dd5",
    "documentDate": "2022-03-01T00:00:00.000Z",
    "isExternal": true,
    "documents": [],
    "deliveryTerms": "",
    "paymentTerms": "CIA",
    "createdAt": "2022-07-04T15:44:14.687Z",
    "updatedAt": "2022-07-04T15:44:15.069Z",
    "version": 2,
    "_etag": "\"070063f7-0000-0d00-0000-62da578e0000\"",
    "_rid": "1U5gAKw+F3MKAAAAAAAAAA==",
    "_self": "dbs/1U5gAA==/colls/1U5gAKw+F3M=/docs/1U5gAKw+F3MKAAAAAAAAAA==/",
    "_attachments": "attachments/",
    "_type": "OrderHeader",
    "_ts": 1658476430
}

Also, any other information that could help us reproduce this scenario.

Sadly we can't say much more. We haven't been able to reproduce it, it seems that happens not always for the same query and we haven't spotted any pattern.

Please let us know if we can provide some more info and thank you very much for looking into this.

charly22 · 2023-02-10T15:52:10Z

We were able to reproduce it 💪

That said, when the result of nextFetchFunction is

{ "result": [ '0': 0 ] }

the FetchResult.constructor fails to detect it's not an error on the following block

        if (feedResponse) {
            this.feedResponse = feedResponse;
            this.fetchResultType = FetchResultType.Result;
        }
        else {
            this.error = error;
            this.fetchResultType = FetchResultType.Exception;
        }

because feedResponse it's evaluated falsy, it enters by the else, the error becomes undefined and that causes the fatal you see on the stack trace.

Hope this information helps you to reproduce it.

### Packages impacted by this PR [@azure/cosmos](https://github.com/Azure/azure-sdk-for-js/tree/main/sdk/cosmosdb/cosmos) ### Issues associated with this PR #24493 ### Describe the problem that is addressed by this PR The code was breaking for any parallel query where the result is `0` or `false` or array of them. Eg. `SELECT value c['type'] from c where c['type']=0`. This fix enables typecheck of the `feedResponse`. ### What are the possible designs available to address the problem? If there are more than one possible design, why was the one in this PR chosen? ### Are there test cases added in this PR? _(If not, why?)_ ### Provide a list of related PRs _(if any)_ ### Command used to generate this PR:**_(Applicable only to SDK release request PRs)_ ### Checklists - [ ] Added impacted package name to the issue description - [ ] Does this PR needs any fixes in the SDK Generator?** _(If so, create an Issue in the [Autorest/typescript](https://github.com/Azure/autorest.typescript) repository and link it here)_ - [ ] Added a changelog (if necessary)

amanrao23 · 2023-03-09T06:01:15Z

Fix is released in v3.17.3

xirzec added Client This issue points to a problem in the data-plane of the library. Cosmos labels Jan 17, 2023

ghost removed the needs-triage Workflow: This is a new issue that needs to be triaged to the appropriate team. label Jan 17, 2023

xirzec assigned sajeetharan Jan 17, 2023

sajeetharan added this to @azure/cosmos Project Jan 20, 2023

sajeetharan assigned amanrao23 Feb 7, 2023

amanrao23 mentioned this issue Feb 13, 2023

Fix Issue-24493: Typecheck feedResponse in FetchResult #24846

Merged

3 tasks

amanrao23 moved this to In Review in @azure/cosmos Project Feb 14, 2023

amanrao23 mentioned this issue Feb 20, 2023

Updated CHANGELOG.md #24824

Merged

3 tasks

v1k1 added a commit to v1k1/azure-sdk-for-js that referenced this issue Feb 21, 2023

Fixed typo and added Azure#24493 to changelog.

64fcbd8

v1k1 added a commit to v1k1/azure-sdk-for-js that referenced this issue Feb 21, 2023

Fixed typo and added Azure#24493 to changelog.

824887d

amanrao23 moved this from In Review to Done in @azure/cosmos Project Feb 23, 2023

amanrao23 added this to the azure-cosmos jan release milestone Feb 23, 2023

amanrao23 closed this as completed Mar 9, 2023

github-actions bot locked and limited conversation to collaborators Jun 7, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Potential bug in `current` function implementation in the Cosmos package #24493

Potential bug in `current` function implementation in the Cosmos package #24493

josegl commented Jan 16, 2023 •

edited

Loading

sajeetharan commented Jan 20, 2023

josegl commented Jan 26, 2023

charly22 commented Jan 30, 2023 •

edited

Loading

charly22 commented Jan 31, 2023

sajeetharan commented Jan 31, 2023

josegl commented Feb 7, 2023

sajeetharan commented Feb 7, 2023

charly22 commented Feb 7, 2023

amanrao23 commented Feb 10, 2023

charly22 commented Feb 10, 2023 •

edited

Loading

charly22 commented Feb 10, 2023 •

edited

Loading

amanrao23 commented Mar 9, 2023

Potential bug in current function implementation in the Cosmos package #24493

Potential bug in current function implementation in the Cosmos package #24493

Comments

josegl commented Jan 16, 2023 • edited Loading

sajeetharan commented Jan 20, 2023

josegl commented Jan 26, 2023

charly22 commented Jan 30, 2023 • edited Loading

charly22 commented Jan 31, 2023

sajeetharan commented Jan 31, 2023

josegl commented Feb 7, 2023

sajeetharan commented Feb 7, 2023

charly22 commented Feb 7, 2023

amanrao23 commented Feb 10, 2023

charly22 commented Feb 10, 2023 • edited Loading

charly22 commented Feb 10, 2023 • edited Loading

amanrao23 commented Mar 9, 2023

Potential bug in `current` function implementation in the Cosmos package #24493

Potential bug in `current` function implementation in the Cosmos package #24493

josegl commented Jan 16, 2023 •

edited

Loading

charly22 commented Jan 30, 2023 •

edited

Loading

charly22 commented Feb 10, 2023 •

edited

Loading

charly22 commented Feb 10, 2023 •

edited

Loading