From 5b2988b9a812eb411f0e7d9c6d66306096a93099 Mon Sep 17 00:00:00 2001 From: Mohammad Derakhshani Date: Thu, 2 Jan 2020 11:17:20 -0800 Subject: [PATCH] logging improvements --- .../implementation/SessionContainer.java | 4 ++- .../caches/RxPartitionKeyRangeCache.java | 2 +- .../directconnectivity/AddressResolver.java | 35 ++++++++++++------- .../directconnectivity/ConsistencyWriter.java | 9 +++-- .../directconnectivity/QuorumReader.java | 17 +++++---- .../directconnectivity/StoreReader.java | 14 ++++---- 6 files changed, 50 insertions(+), 31 deletions(-) diff --git a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/SessionContainer.java b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/SessionContainer.java index 229ac08bfb3a..f9648b0413a4 100644 --- a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/SessionContainer.java +++ b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/SessionContainer.java @@ -187,7 +187,9 @@ private void setSessionToken(ResourceId resourceId, String collectionName, Strin partitionKeyRangeId = tokenParts[0]; parsedSessionToken = SessionTokenHelper.parse(tokenParts[1]); - logger.trace("UPDATE SESSION token {} {} {}", resourceId.getUniqueDocumentCollectionId(), collectionName, parsedSessionToken); + if (logger.isTraceEnabled()) { + logger.trace("UPDATE SESSION token {} {} {}", resourceId.getUniqueDocumentCollectionId(), collectionName, parsedSessionToken); + } boolean isKnownCollection; diff --git a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/caches/RxPartitionKeyRangeCache.java b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/caches/RxPartitionKeyRangeCache.java index 536512009837..e3518735947f 100644 --- a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/caches/RxPartitionKeyRangeCache.java +++ b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/caches/RxPartitionKeyRangeCache.java @@ -98,7 +98,7 @@ public Mono>> tryGetOverlappingRangesA // maybe we should consider changing to ArrayList to avoid conversion return new Utils.ValueHolder<>(new ArrayList<>(routingMapValueHolder.v.getOverlappingRanges(range))); } else { - logger.debug("Routing Map Null for collection: {} for range: {}, forceRefresh:{}", collectionRid, range.toString(), forceRefresh); + logger.debug("Routing Map Null for collection: {} for range: {}, forceRefresh:{}", collectionRid, range, forceRefresh); return new Utils.ValueHolder<>(null); } }); diff --git a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/AddressResolver.java b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/AddressResolver.java index c8f48eaa6a3e..38079276780f 100644 --- a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/AddressResolver.java +++ b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/AddressResolver.java @@ -161,19 +161,23 @@ private static void ensureRoutingMapPresent( // which doesn't exist, we return InvalidPartitionException. Backend does the same. // Caller (client SDK or whoever attached the header) supposedly has outdated collection cache and will refresh it. // We cannot retry here, as the logic for retry in this case is use-case specific. - logger.debug( - "Routing map for request with partitionkeyrageid {} was not found", - request.getPartitionKeyRangeIdentity().toHeader()); + if (logger.isDebugEnabled()) { + logger.debug( + "Routing map for request with partitionkeyrageid {} was not found", + request.getPartitionKeyRangeIdentity().toHeader()); + } InvalidPartitionException invalidPartitionException = new InvalidPartitionException(); BridgeInternal.setResourceAddress(invalidPartitionException, request.getResourceAddress()); throw invalidPartitionException; } if (routingMap == null) { - logger.debug( - "Routing map was not found although collection cache is upto date for collection {}", - collection.getResourceId()); + if (logger.isDebugEnabled()) { + logger.debug( + "Routing map was not found although collection cache is upto date for collection {}", + collection.getResourceId()); + } // Routing map not found although collection was resolved correctly. NotFoundException e = new NotFoundException(); BridgeInternal.setResourceAddress(e, request.getResourceAddress()); @@ -577,7 +581,9 @@ private Mono> tryResolveServerPartitionByPar PartitionKeyRange partitionKeyRange = routingMap.getRangeByPartitionKeyRangeId(request.getPartitionKeyRangeIdentity().getPartitionKeyRangeId()); if (partitionKeyRange == null) { - logger.debug("Cannot resolve range '{}'", request.getPartitionKeyRangeIdentity().toHeader()); + if (logger.isDebugEnabled()) { + logger.debug("Cannot resolve range '{}'", request.getPartitionKeyRangeIdentity().toHeader()); + } return returnOrError(() -> new Utils.ValueHolder<>(this.handleRangeAddressResolutionFailure(request, collectionCacheIsUpToDate, routingMapCacheIsUpToDate, routingMap))); } @@ -588,8 +594,9 @@ private Mono> tryResolveServerPartitionByPar return addressesObs.flatMap(addressesValueHolder -> { if (addressesValueHolder.v == null) { - logger.debug("Cannot resolve addresses for range '{}'", request.getPartitionKeyRangeIdentity().toHeader()); - + if (logger.isDebugEnabled()) { + logger.debug("Cannot resolve addresses for range '{}'", request.getPartitionKeyRangeIdentity().toHeader()); + } try { return Mono.just(new Utils.ValueHolder<>(this.handleRangeAddressResolutionFailure(request, collectionCacheIsUpToDate, routingMapCacheIsUpToDate, routingMap))); } catch (CosmosClientException e) { @@ -666,10 +673,12 @@ private PartitionKeyRange tryResolveServerPartitionByPartitionKey( // * If collection rid doesn't match, server will send back InvalidPartiitonException and GATEWAY will // refresh name routing cache - this will refresh partition key definition as well, and retry. - logger.debug( - "Cannot compute effective partition getKey. Definition has '{}' getPaths, values supplied has '{}' getPaths. Will refresh cache and retry.", - collection.getPartitionKey().getPaths().size(), - partitionKey.getComponents().size()); + if (logger.isDebugEnabled()) { + logger.debug( + "Cannot compute effective partition getKey. Definition has '{}' getPaths, values supplied has '{}' getPaths. Will refresh cache and retry.", + collection.getPartitionKey().getPaths().size(), + partitionKey.getComponents().size()); + } return null; } diff --git a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/ConsistencyWriter.java b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/ConsistencyWriter.java index 6c5e3325ff0d..41ddd62140fb 100644 --- a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/ConsistencyWriter.java +++ b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/ConsistencyWriter.java @@ -320,9 +320,12 @@ private Mono waitForWriteBarrierAsync(RxDocumentServiceRequest barrierR //get max global committed lsn from current batch of responses, then update if greater than max of all batches. if (writeBarrierRetryCount.getAndDecrement() == 0) { - logger.debug("ConsistencyWriter: WaitForWriteBarrierAsync - Last barrier multi-region strong. Responses: {}", - responses.stream().map(StoreResult::toString).collect(Collectors.joining("; "))); - logger.debug("ConsistencyWriter: Highest global committed lsn received for write barrier call is {}", maxGlobalCommittedLsnReceived); + if (logger.isDebugEnabled()) { + + logger.debug("ConsistencyWriter: WaitForWriteBarrierAsync - Last barrier multi-region strong. Responses: {}", + responses.stream().map(StoreResult::toString).collect(Collectors.joining("; "))); + logger.debug("ConsistencyWriter: Highest global committed lsn received for write barrier call is {}", maxGlobalCommittedLsnReceived); + } return Mono.just(Boolean.FALSE); } diff --git a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/QuorumReader.java b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/QuorumReader.java index eb8269506c4f..3c3efab0ea86 100644 --- a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/QuorumReader.java +++ b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/QuorumReader.java @@ -541,9 +541,10 @@ private Mono waitForReadBarrierAsync( barrierRequest.requestContext.forceRefreshAddressCache = false; if (readBarrierRetryCount.decrementAndGet() == 0) { - logger.debug("QuorumReader: waitForReadBarrierAsync - Last barrier for single-region requests. Responses: {}", - JavaStreamUtils.toString(responses, "; ")); - + if (logger.isDebugEnabled()) { + logger.debug("QuorumReader: waitForReadBarrierAsync - Last barrier for single-region requests. Responses: {}", + JavaStreamUtils.toString(responses, "; ")); + } // retries exhausted return Flux.just(false); @@ -591,11 +592,13 @@ private Mono waitForReadBarrierAsync( //trace on last retry. if (readBarrierRetryCountMultiRegion.getAndDecrement() == 0) { - logger.debug("QuorumReader: waitForReadBarrierAsync - Last barrier for mult-region strong requests. Responses: {}", - JavaStreamUtils.toString(responses, "; ")); - return Flux.just(false); + if (logger.isDebugEnabled()) { + logger.debug("QuorumReader: waitForReadBarrierAsync - Last barrier for mult-region strong requests. Responses: {}", + JavaStreamUtils.toString(responses, "; ")); + } + return Flux.just(false); } else { - return Flux.empty(); + return Flux.empty(); } } ); diff --git a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/StoreReader.java b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/StoreReader.java index 067d496faaab..a0eff77481a2 100644 --- a/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/StoreReader.java +++ b/sdk/cosmos/azure-cosmos/src/main/java/com/azure/cosmos/implementation/directconnectivity/StoreReader.java @@ -294,12 +294,14 @@ private ReadReplicaResult createReadReplicaResult(List responseResu boolean hasGoneException, RxDocumentServiceRequest entity) throws CosmosClientException { if (responseResult.size() < replicaCountToRead) { - logger.debug("Could not get quorum number of responses. " + - "ValidResponsesReceived: {} ResponsesExpected: {}, ResolvedAddressCount: {}, ResponsesString: {}", - responseResult.size(), - replicaCountToRead, - resolvedAddressCount, - String.join(";", responseResult.stream().map(r -> r.toString()).collect(Collectors.toList()))); + if (logger.isDebugEnabled()) { + logger.debug("Could not get quorum number of responses. " + + "ValidResponsesReceived: {} ResponsesExpected: {}, ResolvedAddressCount: {}, ResponsesString: {}", + responseResult.size(), + replicaCountToRead, + resolvedAddressCount, + String.join(";", responseResult.stream().map(r -> r.toString()).collect(Collectors.toList()))); + } if (hasGoneException) { if (!entity.requestContext.performLocalRefreshOnGoneException) {