in evcache-core/src/main/java/com/netflix/evcache/operation/EVCacheBulkGetFuture.java [69:157]
public Map<String, T> getSome(long to, TimeUnit unit, boolean throwException, boolean hasZF)
throws InterruptedException, ExecutionException {
assert operationStates != null;
boolean allCompleted = latch.await(to, unit);
if(log.isDebugEnabled()) log.debug("Took " + (System.currentTimeMillis() - start)+ " to fetch " + rvMap.size() + " keys from " + client);
long pauseDuration = -1;
List<Tag> tagList = null;
String statusString = EVCacheMetricsFactory.SUCCESS;
try {
if (!allCompleted) {
boolean gcPause = false;
tagList = new ArrayList<Tag>(7);
tagList.addAll(client.getTagList());
tagList.add(new BasicTag(EVCacheMetricsFactory.CALL_TAG, EVCacheMetricsFactory.BULK_OPERATION));
final RuntimeMXBean runtimeBean = ManagementFactory.getRuntimeMXBean();
final long vmStartTime = runtimeBean.getStartTime();
final List<GarbageCollectorMXBean> gcMXBeans = ManagementFactory.getGarbageCollectorMXBeans();
for (GarbageCollectorMXBean gcMXBean : gcMXBeans) {
if (gcMXBean instanceof com.sun.management.GarbageCollectorMXBean) {
final GcInfo lastGcInfo = ((com.sun.management.GarbageCollectorMXBean) gcMXBean).getLastGcInfo();
// If no GCs, there was no pause.
if (lastGcInfo == null) {
continue;
}
final long gcStartTime = lastGcInfo.getStartTime() + vmStartTime;
if (gcStartTime > start) {
gcPause = true;
if (log.isDebugEnabled()) log.debug("Total duration due to gc event = " + lastGcInfo.getDuration() + " msec.");
break;
}
}
}
// redo the same op once more since there was a chance of gc pause
if (gcPause) {
allCompleted = latch.await(to, unit);
tagList.add(new BasicTag(EVCacheMetricsFactory.PAUSE_REASON, EVCacheMetricsFactory.GC));
if (log.isDebugEnabled()) log.debug("Retry status : " + allCompleted);
if (allCompleted) {
tagList.add(new BasicTag(EVCacheMetricsFactory.FETCH_AFTER_PAUSE, EVCacheMetricsFactory.YES));
} else {
tagList.add(new BasicTag(EVCacheMetricsFactory.FETCH_AFTER_PAUSE, EVCacheMetricsFactory.NO));
}
} else {
tagList.add(new BasicTag(EVCacheMetricsFactory.PAUSE_REASON, EVCacheMetricsFactory.SCHEDULE));
}
pauseDuration = System.currentTimeMillis() - start;
if (log.isDebugEnabled()) log.debug("Total duration due to gc event = " + (System.currentTimeMillis() - start) + " msec.");
}
boolean hadTimedoutOp = false;
for (int i = 0; i < operationStates.length(); i++) {
SingleOperationState state = operationStates.get(i);
if (!state.completed && !allCompleted) {
MemcachedConnection.opTimedOut(state.op);
hadTimedoutOp = true;
} else {
MemcachedConnection.opSucceeded(state.op);
}
}
if (!allCompleted && !hasZF && hadTimedoutOp) statusString = EVCacheMetricsFactory.TIMEOUT;
for (int i = 0; i < operationStates.length(); i++) {
SingleOperationState state = operationStates.get(i);
if (state.cancelled) {
if (hasZF) statusString = EVCacheMetricsFactory.CANCELLED;
if (throwException) throw new ExecutionException(new CancellationException("Cancelled"));
}
if (state.errored && throwException) throw new ExecutionException(state.op.getException());
}
Map<String, T> m = new HashMap<String, T>();
for (Map.Entry<String, Future<T>> me : rvMap.entrySet()) {
m.put(me.getKey(), me.getValue().get());
}
return m;
} finally {
if(pauseDuration > 0) {
tagList.add(new BasicTag(EVCacheMetricsFactory.OPERATION_STATUS, statusString));
EVCacheMetricsFactory.getInstance().getPercentileTimer(EVCacheMetricsFactory.INTERNAL_PAUSE, tagList, Duration.ofMillis(EVCacheConfig.getInstance().getPropertyRepository().get(getApp() + ".max.read.duration.metric", Integer.class)
.orElseGet("evcache.max.read.duration.metric").orElse(20).get().intValue())).record(pauseDuration, TimeUnit.MILLISECONDS);
}
}
}