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

Diagnostics: Fix InvalidOperationException and converts elapsed time to millisecond #1469

Merged
merged 10 commits into from
May 8, 2020

Conversation

j82w
Copy link
Contributor

@j82w j82w commented May 5, 2020

Pull Request Template

Description

  1. Fixed an issue where if user called diagnostics.ToString() is some case could cause an exception because diagnostics are still getting added during the ToString operation. Fixes InvalidOperationException on reading diagnostics string representation #1467
  2. All elapsed time are converted to milliseconds. This was feedback from issue Query Diagnostic improvements #1418
  3. Added correlation id to query to be able to correlate multiple query page diagnostics
  4. Added new diagnostic type for RequestHandlers. This allows it to be marked as a handler in the output.
  5. Added a version to the diagnostics. There currently is not test validating the versioning. For now it can be manually enforced.

Type of change

Please delete options that are not relevant.

  • Bug fix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Breaking change (fix or feature that would cause existing functionality to not work as expected)
  • This change requires a documentation update
{
    "DiagnosticVersion": "2",
    "Summary": {
        "StartUtc": "2020-05-07T21:14:28.6271855Z",
        "TotalElapsedTimeInMs": 235.7414,
        "UserAgent": "cosmos-netstandard-sdk/3.8.0|3.9.0|22795|X64|Microsoft Windows 10.0.18363 |.NET Core 4.6.28619.01|",
        "TotalRequestCount": 4,
        "FailedRequestCount": 0
    },
    "Context": [
        {
            "Id": "CreateQueryPipeline",
            "ElapsedTimeInMs": 85.9766
        },
        {
            "Id": "ServiceInterop",
            "ElapsedTimeInMs": 49.2242
        },
        {
            "PKRangeId": "0",
            "StartUtc": "2020-05-07T21:14:28.7326435Z",
            "QueryMetric": "totalExecutionTimeInMs=1.18;queryCompileTimeInMs=0.28;queryLogicalPlanBuildTimeInMs=0.10;queryPhysicalPlanBuildTimeInMs=0.18;queryOptimizationTimeInMs=0.00;VMExecutionTimeInMs=0.08;indexLookupTimeInMs=0.00;documentLoadTimeInMs=0.04;systemFunctionExecuteTimeInMs=0.00;userFunctionExecuteTimeInMs=0.00;retrievedDocumentCount=1;retrievedDocumentSize=679;outputDocumentCount=1;outputDocumentSize=728;writeOutputTimeInMs=0.00;indexUtilizationRatio=1.00",
            "IndexUtilization": "",
            "ClientCorrelationId": "fe70fa9e-fb16-4976-b87f-96ac359a31a0",
            "Context": [
                {
                    "Id": "AggregatedClientSideRequestStatistics",
                    "ContactedReplicas": [],
                    "RegionsContacted": [
                        "https://127.0.0.1:8081/"
                    ],
                    "FailedReplicas": []
                },
                {
                    "Id": "Microsoft.Azure.Cosmos.Handlers.RetryHandler",
                    "HandlerElapsedTimeInMs": 40.193000000000005
                },
                {
                    "Id": "Microsoft.Azure.Cosmos.Handlers.RouterHandler",
                    "HandlerElapsedTimeInMs": 40.175000000000004
                },
                {
                    "Id": "Microsoft.Azure.Cosmos.Handlers.TransportHandler",
                    "HandlerElapsedTimeInMs": 36.321400000000004
                },
                {
                    "Id": "Microsoft.Azure.Documents.ServerStoreModel",
                    "ElapsedTimeInMs": 39.8268
                },
                {
                    "Id": "StoreResponseStatistics",
                    "StartTimeUtc": "2020-05-07T21:14:28.7388971Z",
                    "ResponseTimeUtc": "2020-05-07T21:14:28.7682907Z",
                    "ElapsedTimeInMs": 29.393600000000003,
                    "ResourceType": "Document",
                    "OperationType": "Query",
                    "LocationEndpoint": "https://127.0.0.1:8081/",
                    "StoreResult": "StorePhysicalAddress: rntbd://127.0.0.1:10253/apps/DocDbApp/services/DocDbServer11/partitions/a4cb4957-38c8-11e6-8106-8cdcd42c33be/replicas/1p/, LSN: 4, GlobalCommittedLsn: -1, PartitionKeyRangeId: 0, IsValid: True, StatusCode: 200, SubStatusCode: 0, RequestCharge: 2.29, ItemLSN: -1, SessionToken: -1#4, UsingLocalLSN: True, TransportException: null"
                }
            ]
        }
    ]
}

@j82w j82w added the Diagnostics Issues around diagnostics and troubleshooting label May 5, 2020
@j82w j82w self-assigned this May 5, 2020
@j82w j82w changed the title Diagnostics: Fixes and conversion to millisecond Diagnostics: Fixes InvalidOperationException and converts elapsed time to millisecond May 5, 2020
Copy link

@github-actions github-actions bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please follow the required format: "[Internal] Category: (Add|Fix|Refactor) Description"

Examples:
Diagnostics: Add GetElapsedClientLatency to CosmosDiagnostics
PartitionKey: Fix null reference when using default(PartitionKey)
[v4] Client Encryption: Refactor code to external project
[Internal] Query: Add code generator for CosmosNumbers for easy additions in the future.

@j82w j82w changed the title Diagnostics: Fixes InvalidOperationException and converts elapsed time to millisecond Diagnostics: Fix InvalidOperationException and converts elapsed time to millisecond May 5, 2020
Copy link

@github-actions github-actions bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please follow the required format: "[Internal] Category: (Add|Fix|Refactor) Description"

Examples:
Diagnostics: Add GetElapsedClientLatency to CosmosDiagnostics
PartitionKey: Fix null reference when using default(PartitionKey)
[v4] Client Encryption: Refactor code to external project
[Internal] Query: Add code generator for CosmosNumbers for easy additions in the future.

@github-actions github-actions bot dismissed stale reviews from themself May 5, 2020 15:22

All good!

kirankumarkolli
kirankumarkolli previously approved these changes May 6, 2020
@j82w j82w dismissed stale reviews from FabianMeiswinkel and kirankumarkolli via a3d9b1d May 7, 2020 16:52
kirankumarkolli
kirankumarkolli previously approved these changes May 7, 2020
@j82w j82w added the bug Something isn't working label May 7, 2020
bchong95
bchong95 previously approved these changes May 7, 2020
Copy link
Contributor

@bchong95 bchong95 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

:shipit:

@j82w j82w dismissed stale reviews from bchong95 and kirankumarkolli via 52d3d1b May 7, 2020 22:01
@j82w j82w merged commit 0f56271 into master May 8, 2020
@j82w j82w deleted the users/jawilley/diagnostics/improvements branch May 8, 2020 18:21
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working Diagnostics Issues around diagnostics and troubleshooting
Projects
None yet
Development

Successfully merging this pull request may close these issues.

InvalidOperationException on reading diagnostics string representation
5 participants