You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@openwhisk.apache.org by GitBox <gi...@apache.org> on 2019/09/30 12:15:57 UTC
[GitHub] [openwhisk] chetanmeh opened a new pull request #4652: Capture
document size, RU usage, retry stats for get and put in CosmosDB
chetanmeh opened a new pull request #4652: Capture document size, RU usage, retry stats for get and put in CosmosDB
URL: https://github.com/apache/openwhisk/pull/4652
This PR enables capturing stats related to document size and RU used for get and put operation.
## Description
### Document Size Stats
With this PR the `get` and `put` operation would include the document size and RU used
```
[2019-09-30T11:29:53.553Z] [INFO] [#tid_1] [CosmosDBArtifactStore] [PUT] 'subjects' completed document: 'id: anon-OIPNjW7IigJetLxDwwlPwlcG2Fl, rev: null', size=235, ru=7.05 [marker:database_saveDocument_finish:9308:685]
```
Further the PR also add a histogram for document size.
### Client Diagnostic Stats
If the `TransactionId` has debug mode enabled (extension of support added in #4275) then it would also include some client side diagnostic info generated by CosmosDB when using `Direct` mode
```
[2019-09-30T11:50:34.472Z] [INFO] [#tid_42] [CosmosDBArtifactStore] [PUT] 'subjects' completed document: 'id: anon-MZIVqUOiMiyxxYXJTyLxYnihVNI, rev: null', size=235, ru=7.05 RequestStartTime: "30 Sep 2019 11:50:30.908", RequestEndTime: "30 Sep 2019 11:50:34.464", Duration: 3556 ms, Number of regions attempted: 1 StoreResponseStatistics{requestResponseTime="30 Sep 2019 11:50:33.281", storeResult=storePhysicalAddress: rntbd://cdb-ms-prod-eastus1-fd18.documents.azure.com:14047/apps/a12ab0b2-98f6-4f5a-a7d4-f67e3a08d496/services/e50f5eae-0700-4539-9323-e4a587786587/partitions/eaa72284-4d0b-4ddf-a919-c890c12803a3/replicas/132138294859720735p/, lsn: 1177, globalCommittedLsn: 1176, partitionKeyRangeId: 0, isValid: true, statusCode: 201, subStatusCode: 0, isGone: false, isNotFound: false, isInvalidPartition: false, requestCharge: 7.05, itemLSN: -1, sessionToken: -1#1177, exception: null, requestResourceType=Document, requestOperationType=Create} AddressResolutionStatistics{startTime="30 Sep 2019 11:50:31.471", endTime="30 Sep 2019 11:50:31.705", targetEndpoint='https://foo-eastus.documents.azure.com:443/addresses/?$resolveFor=dbs%2FXk1oAA%3D%3D%2Fcolls%2FXk1oAKUKbiU%3D%2Fdocs&$filter=protocol%20eq%20rntbd&$partitionKeyRangeIds=0'} StoreResponseStatistics{requestResponseTime="30 Sep 2019 11:50:34.464", storeResult=storePhysicalAddress: rntbd://cdb-ms-prod-eastus1-fd18.documents.azure.com:14064/apps/a12ab0b2-98f6-4f5a-a7d4-f67e3a08d496/services/e50f5eae-0700-4539-9323-e4a587786587/partitions/eaa72284-4d0b-4ddf-a919-c890c12803a3/replicas/132119752170912464s/, lsn: 1177, globalCommittedLsn: 1177, partitionKeyRangeId: 0, isValid: true, statusCode: 204, subStatusCode: 0, isGone: false, isNotFound: false, isInvalidPartition: false, requestCharge: 0.0, itemLSN: 660, sessionToken: -1#1177, exception: null, requestResourceType=DocumentCollection, requestOperationType=Head} [marker:database_saveDocument_finish:15080:3568]
```
### Retry stats
The PR also enabled to capture the internal retry done by SDK upon throttling. Currently there is no direct support to capture such stats (Azure/azure-cosmosdb-java#262). So this PR makes use of Logback to capture the stats by intercepting the warning log message generated upon a 429 response
```
[2019-09-27T07:57:15.161Z] [WARN] Operation will be retried after 6 milliseconds. [2019-09-27T07:57:15.161Z] [WARN] Operation will be retried after 6 milliseconds. Current attempt 1, Cumulative delay PT0.006S
com.microsoft.azure.cosmosdb.DocumentClientException: Message: {"Errors":["Request rate is large"]}
ActivityId: 28ebd9fc-2615-4e9f-b4a7-ec3ebb464b36, Request URI: /apps/cebf41ab-a2c2-4055-b592-9887b5c5a634/services/91918f88-9f66-459c-93cf-53644d05f280/partitions/2baa1e8f-3751-444c-8be7-f831dc692a63/replicas/132121471945325759p/, RequestStats:
RequestStartTime: 2019-09-27T07:57:14.6731085Z, RequestEndTime: 2019-09-27T07:57:14.6731085Z, Number of regions attempted: 1
ResponseTime: 2019-09-27T07:57:14.6731085Z, StoreResult: StorePhysicalAddress: rntbd://cdb-ms-prod-eastus1-fd34.documents.azure.com:16701/apps/cebf41ab-a2c2-4055-b592-9887b5c5a634/services/91918f88-9f66-459c-93cf-53644d05f280/partitions/2baa1e8f-3751-444c-8be7-f831dc692a63/replicas/132121471945325759p/, LSN: 1898, GlobalCommittedLsn: 1897, PartitionKeyRangeId: , IsValid: True, StatusCode: 429, SubStatusCode: 3200, RequestCharge: 0.38, ItemLSN: -1, SessionToken: , UsingLocalLSN: False, TransportException: null, ResourceType: Document, OperationType: Create
, SDK: Microsoft.Azure.Documents.Common/2.5.1, StatusCode: TooManyRequests
at com.microsoft.azure.cosmosdb.rx.internal.RxGatewayStoreModel.validateOrThrow(RxGatewayStoreModel.java:444)
at com.microsoft.azure.cosmosdb.rx.internal.RxGatewayStoreModel.lambda$null$8(RxGatewayStoreModel.java:382)
```
A typical log message looks like above which has info related to
1. Attempt count
2. If retry would be done or it was the last retry
3. Operation type like Get or Create etc
## Related issue and scope
<!--- Please include a link to a related issue if there is one. -->
- [ ] I opened an issue to propose and discuss this change (#????)
## My changes affect the following components
<!--- Select below all system components are affected by your change. -->
<!--- Enter an `x` in all applicable boxes. -->
- [ ] API
- [ ] Controller
- [ ] Message Bus (e.g., Kafka)
- [ ] Loadbalancer
- [ ] Invoker
- [ ] Intrinsic actions (e.g., sequences, conductors)
- [ ] Data stores (e.g., CouchDB)
- [ ] Tests
- [ ] Deployment
- [ ] CLI
- [ ] General tooling
- [ ] Documentation
## Types of changes
<!--- What types of changes does your code introduce? Use `x` in all the boxes that apply: -->
- [ ] Bug fix (generally a non-breaking change which closes an issue).
- [ ] Enhancement or new feature (adds new functionality).
- [ ] Breaking change (a bug fix or enhancement which changes existing behavior).
## Checklist:
<!--- Please review the points below which help you make sure you've covered all aspects of the change you're making. -->
- [ ] I signed an [Apache CLA](https://github.com/apache/openwhisk/blob/master/CONTRIBUTING.md).
- [ ] I reviewed the [style guides](https://github.com/apache/openwhisk/wiki/Contributing:-Git-guidelines#code-readiness) and followed the recommendations (Travis CI will check :).
- [ ] I added tests to cover my changes.
- [ ] My changes require further changes to the documentation.
- [ ] I updated the documentation where necessary.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services