Converting cosmos exception into json format #18092

simplynaveen20 · 2020-12-11T20:15:03Z

Currently CosmosException toString() and getMessage() method return a mix of non-json text and json diagnostic information.
This is causing problems during debugging the issue when the customer reports the exception.
This PR will convert both toString() and getMessage() into json format. Added test coverage to avoid future contract break.

Examples
toString()-
{
"ClassName": "NotFoundException",
"userAgent": "azsdk-java-cosmos/4.10.0 Windows10/10.0 JRE/11.0.6",
"statusCode": 404,
"resourceAddress": "rntbd://127.0.0.1:10253/apps/DocDbApp/services/DocDbServer20/partitions/a4cb4960-38c8-11e6-8106-8cdcd42c33be/replicas/1p/",
"error": "{"Errors":["Resource Not Found. Learn more: https://aka.ms/cosmosdb-tsg-not-found"]}",
"innerErrorMessage": "["Resource Not Found. Learn more: https://aka.ms/cosmosdb-tsg-not-found"]",
"causeInfo": null,
"responseHeaders": "{x-ms-current-replica-set-size=1, x-ms-last-state-change-utc=Tue, 15 Dec 2020 19:26:43.217 GMT, x-ms-session-token=0:-1#1632, lsn=1632, x-ms-request-charge=1.0, x-ms-schemaversion=1.10, x-ms-transport-request-id=2, x-ms-number-of-read-regions=0, x-ms-current-write-quorum=1, x-ms-cosmos-quorum-acked-llsn=1632, x-ms-quorum-acked-lsn=1632, x-ms-activity-id=42c69559-3f0c-11eb-9f3c-59b9e4f788a5, x-ms-xp-role=0, x-ms-global-Committed-lsn=-1, x-ms-cosmos-llsn=1632, x-ms-serviceversion= version=2.11.0.0}",
"cosmosDiagnostics": {
"userAgent": "azsdk-java-cosmos/4.10.0 Windows10/10.0 JRE/11.0.6",
"requestLatencyInMs": 392,
"requestStartTimeUTC": "2020-12-15T19:32:25.730376600Z",
"requestEndTimeUTC": "2020-12-15T19:32:26.122406500Z",
"connectionMode": "DIRECT",
"responseStatisticsList": [
{
"storeResult": {
"storePhysicalAddress": null,
"lsn": 1632,
"globalCommittedLsn": -1,
"partitionKeyRangeId": "0",
"isValid": true,
"statusCode": 404,
"subStatusCode": 0,
"isGone": false,
"isNotFound": true,
"isInvalidPartition": false,
"requestCharge": 1,
"itemLSN": -1,
"sessionToken": "-1#1632",
"exception": "["Resource Not Found. Learn more: https://aka.ms/cosmosdb-tsg-not-found"]",
"transportRequestTimeline": [
{
"eventName": "created",
"startTimeUTC": "2020-12-15T19:32:26.025410700Z",
"durationInMicroSec": 1993
},
{
"eventName": "queued",
"startTimeUTC": "2020-12-15T19:32:26.027404500Z",
"durationInMicroSec": 0
},
{
"eventName": "channelAcquisitionStarted",
"startTimeUTC": "2020-12-15T19:32:26.027404500Z",
"durationInMicroSec": 36003
},
{
"eventName": "pipelined",
"startTimeUTC": "2020-12-15T19:32:26.063407800Z",
"durationInMicroSec": 13000
},
{
"eventName": "transitTime",
"startTimeUTC": "2020-12-15T19:32:26.076407900Z",
"durationInMicroSec": 2998
},
{
"eventName": "received",
"startTimeUTC": "2020-12-15T19:32:26.079406600Z",
"durationInMicroSec": 32000
},
{
"eventName": "completed",
"startTimeUTC": "2020-12-15T19:32:26.111407100Z",
"durationInMicroSec": 8000
}
],
"rntbdRequestLengthInBytes": 463,
"rntbdResponseLengthInBytes": 283,
"requestPayloadLengthInBytes": 0,
"responsePayloadLengthInBytes": null,
"channelTaskQueueSize": 1,
"pendingRequestsCount": 1,
"serviceEndpointStatistics": {
"availableChannels": 0,
"acquiredChannels": 0,
"executorTaskQueueSize": 0,
"inflightRequests": 1,
"lastSuccessfulRequestTime": "2020-12-15T19:32:26.026Z",
"lastRequestTime": "2020-12-15T19:32:26.026Z",
"createdTime": "2020-12-15T19:32:26.026406900Z",
"isClosed": false
}
},
"requestResponseTimeUTC": "2020-12-15T19:32:26.122406500Z",
"requestResourceType": "Document",
"requestOperationType": "Read"
}
],
"supplementalResponseStatisticsList": [],
"addressResolutionStatistics": {
"42ded84d-3f0c-11eb-9f3c-59b9e4f788a5": {
"startTimeUTC": "2020-12-15T19:32:25.900406600Z",
"endTimeUTC": "2020-12-15T19:32:25.917410400Z",
"targetEndpoint": "https://127.0.0.1:8081/addresses/?$resolveFor=dbs%2FRuR-AA%3D%3D%2Fcolls%2FRuR-AKEqke8%3D%2Fdocs&$filter=protocol%20eq%20rntbd&$partitionKeyRangeIds=0",
"errorMessage": null,
"inflightRequest": false
}
},
"regionsContacted": [
"https://127.0.0.1:8081/"
],
"retryContext": {
"retryCount": 0,
"statusAndSubStatusCodes": null,
"retryLatency": 0
},
"metadataDiagnosticsContext": {
"metadataDiagnosticList": [
{
"metaDataName": "CONTAINER_LOOK_UP",
"startTimeUTC": "2020-12-15T19:32:25.750382200Z",
"endTimeUTC": "2020-12-15T19:32:25.789377600Z",
"durationinMS": 38
},
{
"metaDataName": "PARTITION_KEY_RANGE_LOOK_UP",
"startTimeUTC": "2020-12-15T19:32:25.857394800Z",
"endTimeUTC": "2020-12-15T19:32:25.894406900Z",
"durationinMS": 37
},
{
"metaDataName": "SERVER_ADDRESS_LOOKUP",
"startTimeUTC": "2020-12-15T19:32:25.900406600Z",
"endTimeUTC": "2020-12-15T19:32:25.917410400Z",
"durationinMS": 17
}
]
},
"serializationDiagnosticsContext": {
"serializationDiagnosticsList": null
},
"gatewayStatistics": null,
"systemInformation": {
"usedMemory": "79083 KB",
"availableMemory": "4074261 KB",
"systemCpuLoad": "(2020-12-15T19:32:22.653618900Z 33.7%), (2020-12-15T19:32:22.990406700Z 33.7%)"
},
"clientCfgs": {
"id": -2,
"numberOfClients": 4,
"connCfg": {
"rntbd": "(cto:PT5S, rto:PT5S, icto:PT0S, ieto:PT1H, mcpe:130, mrpc:30, cer:false)",
"gw": "(cps:1000, rto:PT5S, icto:null, p:false)",
"other": "(ed: true, cs: false)"
},
"consistencyCfg": "(consistency: null, mm: true, prgns: [])"
}
}
}

getMessage()-
{
"innerErrorMessage": "["Resource Not Found. Learn more: https://aka.ms/cosmosdb-tsg-not-found"]",
"cosmosDiagnostics": {
"userAgent": "azsdk-java-cosmos/4.10.0 Windows10/10.0 JRE/11.0.6",
"requestLatencyInMs": 392,
"requestStartTimeUTC": "2020-12-15T19:32:25.730376600Z",
"requestEndTimeUTC": "2020-12-15T19:32:26.122406500Z",
"connectionMode": "DIRECT",
"responseStatisticsList": [
{
"storeResult": {
"storePhysicalAddress": null,
"lsn": 1632,
"globalCommittedLsn": -1,
"partitionKeyRangeId": "0",
"isValid": true,
"statusCode": 404,
"subStatusCode": 0,
"isGone": false,
"isNotFound": true,
"isInvalidPartition": false,
"requestCharge": 1,
"itemLSN": -1,
"sessionToken": "-1#1632",
"exception": "["Resource Not Found. Learn more: https://aka.ms/cosmosdb-tsg-not-found"]",
"transportRequestTimeline": [
{
"eventName": "created",
"startTimeUTC": "2020-12-15T19:32:26.025410700Z",
"durationInMicroSec": 1993
},
{
"eventName": "queued",
"startTimeUTC": "2020-12-15T19:32:26.027404500Z",
"durationInMicroSec": 0
},
{
"eventName": "channelAcquisitionStarted",
"startTimeUTC": "2020-12-15T19:32:26.027404500Z",
"durationInMicroSec": 36003
},
{
"eventName": "pipelined",
"startTimeUTC": "2020-12-15T19:32:26.063407800Z",
"durationInMicroSec": 13000
},
{
"eventName": "transitTime",
"startTimeUTC": "2020-12-15T19:32:26.076407900Z",
"durationInMicroSec": 2998
},
{
"eventName": "received",
"startTimeUTC": "2020-12-15T19:32:26.079406600Z",
"durationInMicroSec": 32000
},
{
"eventName": "completed",
"startTimeUTC": "2020-12-15T19:32:26.111407100Z",
"durationInMicroSec": 8000
}
],
"rntbdRequestLengthInBytes": 463,
"rntbdResponseLengthInBytes": 283,
"requestPayloadLengthInBytes": 0,
"responsePayloadLengthInBytes": null,
"channelTaskQueueSize": 1,
"pendingRequestsCount": 1,
"serviceEndpointStatistics": {
"availableChannels": 0,
"acquiredChannels": 0,
"executorTaskQueueSize": 0,
"inflightRequests": 1,
"lastSuccessfulRequestTime": "2020-12-15T19:32:26.026Z",
"lastRequestTime": "2020-12-15T19:32:26.026Z",
"createdTime": "2020-12-15T19:32:26.026406900Z",
"isClosed": false
}
},
"requestResponseTimeUTC": "2020-12-15T19:32:26.122406500Z",
"requestResourceType": "Document",
"requestOperationType": "Read"
}
],
"supplementalResponseStatisticsList": [],
"addressResolutionStatistics": {
"42ded84d-3f0c-11eb-9f3c-59b9e4f788a5": {
"startTimeUTC": "2020-12-15T19:32:25.900406600Z",
"endTimeUTC": "2020-12-15T19:32:25.917410400Z",
"targetEndpoint": "https://127.0.0.1:8081/addresses/?$resolveFor=dbs%2FRuR-AA%3D%3D%2Fcolls%2FRuR-AKEqke8%3D%2Fdocs&$filter=protocol%20eq%20rntbd&$partitionKeyRangeIds=0",
"errorMessage": null,
"inflightRequest": false
}
},
"regionsContacted": [
"https://127.0.0.1:8081/"
],
"retryContext": {
"retryCount": 0,
"statusAndSubStatusCodes": null,
"retryLatency": 0
},
"metadataDiagnosticsContext": {
"metadataDiagnosticList": [
{
"metaDataName": "CONTAINER_LOOK_UP",
"startTimeUTC": "2020-12-15T19:32:25.750382200Z",
"endTimeUTC": "2020-12-15T19:32:25.789377600Z",
"durationinMS": 38
},
{
"metaDataName": "PARTITION_KEY_RANGE_LOOK_UP",
"startTimeUTC": "2020-12-15T19:32:25.857394800Z",
"endTimeUTC": "2020-12-15T19:32:25.894406900Z",
"durationinMS": 37
},
{
"metaDataName": "SERVER_ADDRESS_LOOKUP",
"startTimeUTC": "2020-12-15T19:32:25.900406600Z",
"endTimeUTC": "2020-12-15T19:32:25.917410400Z",
"durationinMS": 17
}
]
},
"serializationDiagnosticsContext": {
"serializationDiagnosticsList": null
},
"gatewayStatistics": null,
"systemInformation": {
"usedMemory": "79083 KB",
"availableMemory": "4074261 KB",
"systemCpuLoad": "(2020-12-15T19:32:22.653618900Z 33.7%), (2020-12-15T19:32:22.990406700Z 33.7%)"
},
"clientCfgs": {
"id": -2,
"numberOfClients": 4,
"connCfg": {
"rntbd": "(cto:PT5S, rto:PT5S, icto:PT0S, ieto:PT1H, mcpe:130, mrpc:30, cer:false)",
"gw": "(cps:1000, rto:PT5S, icto:null, p:false)",
"other": "(ed: true, cs: false)"
},
"consistencyCfg": "(consistency: null, mm: true, prgns: [])"
}
}
}

simplynaveen20 · 2020-12-14T18:25:55Z

/azp run java - cosmos - ci

azure-pipelines · 2020-12-14T18:26:11Z

Azure Pipelines successfully started running 1 pipeline(s).

simplynaveen20 · 2020-12-14T20:51:29Z

/azp run java - cosmos - tests

azure-pipelines · 2020-12-14T20:51:40Z

Azure Pipelines successfully started running 1 pipeline(s).

moderakh

Thank you Naveen for the PR. This is helpful.
@simplynaveen20 Could you please add a sample exception stacktrace to the PR description?

also:
Serializing diagnostics is expensive and will have perf impact.

Now that we are doing that in the exception stacktrace for each exception we should exclude the business logic errors:

NotFound (with no substatus code, i.e., for READ_SESSION_NOT_AVAILABLE we need diagnostics),
Conflict,
PreconditionFailed.

These are business logic failures we don't need to the diagnostics for this.

NotFound with READ_SESSION_NOT_AVAILABLE substatus code is a consistency failure not business logic we should have diagnostics for that.

sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/CosmosDiagnostics.java

sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/CosmosException.java

simplynaveen20 · 2020-12-15T19:55:50Z

Thank you Naveen for the PR. This is helpful.
@simplynaveen20 Could you please add a sample exception stacktrace to the PR description?

also:
Serializing diagnostics is expensive and will have perf impact.

Now that we are doing that in the exception stacktrace for each exception we should exclude the business logic errors:

NotFound (with no substatus code, i.e., for READ_SESSION_NOT_AVAILABLE we need diagnostics),

Conflict,

PreconditionFailed.

These are business logic failures we don't need to the diagnostics for this.

NotFound with READ_SESSION_NOT_AVAILABLE substatus code is a consistency failure not business logic we should have diagnostics for that.

Before this PR we were still serializing diagnostics and putting in string on exception message. In this PR we putting diagnostics object in exception parent ObjectNode and then serializing in json at the last. So for computation on diagnostics serialization still remain the same.
However I see your point in general to avoid diagnostics serialization on regular customer business scenario like 404 not found. I would like to keep it as sperate work item, however there is down side to put custom logic based on status code, we need to maintain extra logic for future scenarios and secondly its customer who should decide whether to fetch the whole message when there is expected failure and can be handle based on expected status code.

simplynaveen20 · 2020-12-15T20:35:57Z

/azp run java - cosmos - tests

azure-pipelines · 2020-12-15T20:36:08Z

Azure Pipelines successfully started running 1 pipeline(s).

simplynaveen20 · 2020-12-16T18:15:02Z

/azp run java - cosmos - tests

azure-pipelines · 2020-12-16T18:15:12Z

Azure Pipelines successfully started running 1 pipeline(s).

moderakh

LGTM. Feel free to capture the following work in a separate PR (work item)

materializing diagnostics in every exception stacktrace for every exception is expensive and has perf impact, we should exclude the business logic errors:

NotFound (with no substatus code, i.e., for READ_SESSION_NOT_AVAILABLE we need diagnostics),
Conflict,
PreconditionFailed.
These are business logic failures we don't need to the diagnostics for this.

NotFound with READ_SESSION_NOT_AVAILABLE substatus code is a consistency failure not business logic we should have diagnostics for that.

Converting cosmos exception json

7f90126

simplynaveen20 requested review from FabianMeiswinkel, kirankumarkolli, kushagraThapar, mbhaskar, milismsft, moderakh and xinlian12 as code owners December 11, 2020 20:15

ghost added the Cosmos label Dec 11, 2020

simplynaveen20 added 4 commits December 11, 2020 15:29

fixing test case

f5e2e77

fixing test case

107d3be

fixing test case

fc26613

Fixing spotbug

d39a839

moderakh suggested changes Dec 14, 2020

View reviewed changes

sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/CosmosDiagnostics.java Outdated Show resolved Hide resolved

sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/CosmosException.java Show resolved Hide resolved

simplynaveen20 added 2 commits December 15, 2020 14:23

Merge branch 'latest-master' into users/nakumars/diagnosticFixes

31e37a2

resolving comments and fixing test case

0c62e97

simplynaveen20 requested a review from moderakh December 15, 2020 19:56

Fixing test case

1f67882

moderakh approved these changes Dec 16, 2020

View reviewed changes

simplynaveen20 mentioned this pull request Dec 18, 2020

Exclude business logic failure (404, 409, 412) during parsing diagnostics on exception #18271

Closed

mbhaskar approved these changes Dec 18, 2020

View reviewed changes

simplynaveen20 merged commit 9383d60 into Azure:master Dec 18, 2020

kushagraThapar mentioned this pull request Mar 25, 2021

Removed afterburner usage from Cosmos Exception #20114

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Converting cosmos exception into json format #18092

Converting cosmos exception into json format #18092

Uh oh!

simplynaveen20 commented Dec 11, 2020 •

edited

Loading

Uh oh!

simplynaveen20 commented Dec 14, 2020

Uh oh!

azure-pipelines bot commented Dec 14, 2020

Uh oh!

simplynaveen20 commented Dec 14, 2020

Uh oh!

azure-pipelines bot commented Dec 14, 2020

Uh oh!

moderakh left a comment •

edited

Loading

Uh oh!

Uh oh!

Uh oh!

simplynaveen20 commented Dec 15, 2020

Uh oh!

simplynaveen20 commented Dec 15, 2020

Uh oh!

azure-pipelines bot commented Dec 15, 2020

Uh oh!

simplynaveen20 commented Dec 16, 2020

Uh oh!

azure-pipelines bot commented Dec 16, 2020

Uh oh!

moderakh left a comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Converting cosmos exception into json format #18092

Converting cosmos exception into json format #18092

Uh oh!

Conversation

simplynaveen20 commented Dec 11, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

simplynaveen20 commented Dec 14, 2020

Uh oh!

azure-pipelines bot commented Dec 14, 2020

Uh oh!

simplynaveen20 commented Dec 14, 2020

Uh oh!

azure-pipelines bot commented Dec 14, 2020

Uh oh!

moderakh left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

simplynaveen20 commented Dec 15, 2020

Uh oh!

simplynaveen20 commented Dec 15, 2020

Uh oh!

azure-pipelines bot commented Dec 15, 2020

Uh oh!

simplynaveen20 commented Dec 16, 2020

Uh oh!

azure-pipelines bot commented Dec 16, 2020

Uh oh!

moderakh left a comment

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

simplynaveen20 commented Dec 11, 2020 •

edited

Loading

moderakh left a comment •

edited

Loading