@Test public void getTraceLogPresentOnTraceLevelEvenIfQueryIsSlow() { Appender mockAppender = setLogLevelAndGetAppender(Level.TRACE); doAnswer(waitASecondAndAHalfAndReturn).when(delegate).get(TABLE_REF, timestampByCell); kvs.get(TABLE_REF, timestampByCell); verify(mockAppender).doAppend(traceLogMatcher.get()); verify(mockAppender).doAppend(slowLogMatcher.get()); }
@Override public Map<Cell, Value> get(TableReference tableRef, Map<Cell, Long> timestampByCell) { long startTime = System.currentTimeMillis(); return KvsProfilingLogger.maybeLog(() -> delegate.get(tableRef, timestampByCell), (logger, stopwatch) -> logger.log("Call to KVS.get at time {}, on table {}, requesting {} cells took {} ms ", LoggingArgs.startTimeMillis(startTime), LoggingArgs.tableRef(tableRef), LoggingArgs.cellCount(timestampByCell.size()), LoggingArgs.durationMillis(stopwatch)), logCellResultSize(4L)); }
ProfilingKeyValueService implements KeyValueService { @Override public Map<Cell, Value> get(TableReference tableRef, Map<Cell, Long> timestampByCell) { long startTime = System.currentTimeMillis(); return KvsProfilingLogger.maybeLog(() -> delegate.get(tableRef, timestampByCell), (logger, stopwatch) -> logger.log("Call to KVS.get at time {}, on table {}, requesting {} cells took {} ms ", LoggingArgs.startTimeMillis(startTime), LoggingArgs.tableRef(tableRef), LoggingArgs.cellCount(timestampByCell.size()), LoggingArgs.durationMillis(stopwatch)), logCellResultSize(4L)); } }
ProfilingKeyValueService implements KeyValueService { @Override public Map<Cell, Value> get(TableReference tableRef, Map<Cell, Long> timestampByCell) { long startTime = System.currentTimeMillis(); return KvsProfilingLogger.maybeLog(() -> delegate.get(tableRef, timestampByCell), (logger, stopwatch) -> logger.log("Call to KVS.get at time {}, on table {}, requesting {} cells took {} ms ", LoggingArgs.startTimeMillis(startTime), LoggingArgs.tableRef(tableRef), LoggingArgs.cellCount(timestampByCell.size()), LoggingArgs.durationMillis(stopwatch)), logCellResultSize(4L)); } private  ProfilingKeyValueService(KeyValueService delegate); }
ProfilingKeyValueService implements KeyValueService { @Override public Map<Cell, Value> get(TableReference tableRef, Map<Cell, Long> timestampByCell) { long startTime = System.currentTimeMillis(); return KvsProfilingLogger.maybeLog(() -> delegate.get(tableRef, timestampByCell), (logger, stopwatch) -> logger.log("Call to KVS.get at time {}, on table {}, requesting {} cells took {} ms ", LoggingArgs.startTimeMillis(startTime), LoggingArgs.tableRef(tableRef), LoggingArgs.cellCount(timestampByCell.size()), LoggingArgs.durationMillis(stopwatch)), logCellResultSize(4L)); } private  ProfilingKeyValueService(KeyValueService delegate); static ProfilingKeyValueService create(KeyValueService delegate); @Deprecated static ProfilingKeyValueService create(KeyValueService delegate, long slowLogThresholdMillis); @Override void addGarbageCollectionSentinelValues(TableReference tableRef, Iterable<Cell> cells); @Override void createTable(TableReference tableRef, byte[] tableMetadata); @Override void createTables(Map<TableReference, byte[]> tableRefToTableMetadata); @Override void delete(TableReference tableRef, Multimap<Cell, Long> keys); @Override void deleteRange(TableReference tableRef, RangeRequest range); @Override void deleteRows(TableReference tableRef, Iterable<byte[]> rows); @Override void deleteAllTimestamps(TableReference tableRef, Map<Cell, TimestampRangeDelete> deletes); @Override void dropTable(TableReference tableRef); @Override void dropTables(Set<TableReference> tableRefs); @Override Map<Cell, Value> get(TableReference tableRef, Map<Cell, Long> timestampByCell); @Override Set<TableReference> getAllTableNames(); @Override Multimap<Cell, Long> getAllTimestamps(TableReference tableRef, Set<Cell> cells, long timestamp); @Override Collection<? extends KeyValueService> getDelegates(); @Override Map<RangeRequest, TokenBackedBasicResultsPage<RowResult<Value>, byte[]>> getFirstBatchForRanges(
            TableReference tableRef, Iterable<RangeRequest> rangeRequests, long timestamp); @Override Map<Cell, Long> getLatestTimestamps(TableReference tableRef, Map<Cell, Long> timestampByCell); @Override byte[] getMetadataForTable(TableReference tableRef); @Override Map<TableReference, byte[]> getMetadataForTables(); @Override ClosableIterator<RowResult<Value>> getRange(TableReference tableRef, RangeRequest rangeRequest,
            long timestamp); @Override ClosableIterator<RowResult<Set<Long>>> getRangeOfTimestamps(TableReference tableRef,
            RangeRequest rangeRequest, long timestamp); @Override ClosableIterator<List<CandidateCellForSweeping>> getCandidateCellsForSweeping(TableReference tableRef,
            CandidateCellForSweepingRequest request); @Override Map<Cell, Value> getRows(TableReference tableRef, Iterable<byte[]> rows, ColumnSelection columnSelection,
            long timestamp); @Override void multiPut(Map<TableReference, ? extends Map<Cell, byte[]>> valuesByTable, long timestamp); @Override void put(TableReference tableRef, Map<Cell, byte[]> values, long timestamp); @Override void putMetadataForTable(TableReference tableRef, byte[] metadata); @Override void putMetadataForTables(Map<TableReference, byte[]> tableRefToMetadata); @Override void putUnlessExists(TableReference tableRef, Map<Cell, byte[]> values); @Override CheckAndSetCompatibility getCheckAndSetCompatibility(); @Override void checkAndSet(CheckAndSetRequest request); @Override void putWithTimestamps(TableReference tableRef, Multimap<Cell, Value> values); @Override void close(); @Override void truncateTable(TableReference tableRef); @Override void truncateTables(Set<TableReference> tableRefs); @Override void compactInternally(TableReference tableRef); @Override ClusterAvailabilityStatus getClusterAvailabilityStatus(); @Override boolean isInitialized(); @Override void compactInternally(TableReference tableRef, boolean inMaintenanceMode); @Override Map<byte[], RowColumnRangeIterator> getRowsColumnRange(TableReference tableRef, Iterable<byte[]> rows,
            BatchColumnRangeSelection batchColumnRangeSelection, long timestamp); @Override RowColumnRangeIterator getRowsColumnRange(TableReference tableRef,
            Iterable<byte[]> rows,
            ColumnRangeSelection columnRangeSelection,
            int cellBatchHint,
            long timestamp); @Override boolean shouldTriggerCompactions(); @Override ListenableFuture<Map<Cell, Value>> getAsync(TableReference tableRef, Map<Cell, Long> timestampByCell); }
ProfilingKeyValueService implements KeyValueService { @Override public Map<Cell, Value> get(TableReference tableRef, Map<Cell, Long> timestampByCell) { long startTime = System.currentTimeMillis(); return KvsProfilingLogger.maybeLog(() -> delegate.get(tableRef, timestampByCell), (logger, stopwatch) -> logger.log("Call to KVS.get at time {}, on table {}, requesting {} cells took {} ms ", LoggingArgs.startTimeMillis(startTime), LoggingArgs.tableRef(tableRef), LoggingArgs.cellCount(timestampByCell.size()), LoggingArgs.durationMillis(stopwatch)), logCellResultSize(4L)); } private  ProfilingKeyValueService(KeyValueService delegate); static ProfilingKeyValueService create(KeyValueService delegate); @Deprecated static ProfilingKeyValueService create(KeyValueService delegate, long slowLogThresholdMillis); @Override void addGarbageCollectionSentinelValues(TableReference tableRef, Iterable<Cell> cells); @Override void createTable(TableReference tableRef, byte[] tableMetadata); @Override void createTables(Map<TableReference, byte[]> tableRefToTableMetadata); @Override void delete(TableReference tableRef, Multimap<Cell, Long> keys); @Override void deleteRange(TableReference tableRef, RangeRequest range); @Override void deleteRows(TableReference tableRef, Iterable<byte[]> rows); @Override void deleteAllTimestamps(TableReference tableRef, Map<Cell, TimestampRangeDelete> deletes); @Override void dropTable(TableReference tableRef); @Override void dropTables(Set<TableReference> tableRefs); @Override Map<Cell, Value> get(TableReference tableRef, Map<Cell, Long> timestampByCell); @Override Set<TableReference> getAllTableNames(); @Override Multimap<Cell, Long> getAllTimestamps(TableReference tableRef, Set<Cell> cells, long timestamp); @Override Collection<? extends KeyValueService> getDelegates(); @Override Map<RangeRequest, TokenBackedBasicResultsPage<RowResult<Value>, byte[]>> getFirstBatchForRanges(
            TableReference tableRef, Iterable<RangeRequest> rangeRequests, long timestamp); @Override Map<Cell, Long> getLatestTimestamps(TableReference tableRef, Map<Cell, Long> timestampByCell); @Override byte[] getMetadataForTable(TableReference tableRef); @Override Map<TableReference, byte[]> getMetadataForTables(); @Override ClosableIterator<RowResult<Value>> getRange(TableReference tableRef, RangeRequest rangeRequest,
            long timestamp); @Override ClosableIterator<RowResult<Set<Long>>> getRangeOfTimestamps(TableReference tableRef,
            RangeRequest rangeRequest, long timestamp); @Override ClosableIterator<List<CandidateCellForSweeping>> getCandidateCellsForSweeping(TableReference tableRef,
            CandidateCellForSweepingRequest request); @Override Map<Cell, Value> getRows(TableReference tableRef, Iterable<byte[]> rows, ColumnSelection columnSelection,
            long timestamp); @Override void multiPut(Map<TableReference, ? extends Map<Cell, byte[]>> valuesByTable, long timestamp); @Override void put(TableReference tableRef, Map<Cell, byte[]> values, long timestamp); @Override void putMetadataForTable(TableReference tableRef, byte[] metadata); @Override void putMetadataForTables(Map<TableReference, byte[]> tableRefToMetadata); @Override void putUnlessExists(TableReference tableRef, Map<Cell, byte[]> values); @Override CheckAndSetCompatibility getCheckAndSetCompatibility(); @Override void checkAndSet(CheckAndSetRequest request); @Override void putWithTimestamps(TableReference tableRef, Multimap<Cell, Value> values); @Override void close(); @Override void truncateTable(TableReference tableRef); @Override void truncateTables(Set<TableReference> tableRefs); @Override void compactInternally(TableReference tableRef); @Override ClusterAvailabilityStatus getClusterAvailabilityStatus(); @Override boolean isInitialized(); @Override void compactInternally(TableReference tableRef, boolean inMaintenanceMode); @Override Map<byte[], RowColumnRangeIterator> getRowsColumnRange(TableReference tableRef, Iterable<byte[]> rows,
            BatchColumnRangeSelection batchColumnRangeSelection, long timestamp); @Override RowColumnRangeIterator getRowsColumnRange(TableReference tableRef,
            Iterable<byte[]> rows,
            ColumnRangeSelection columnRangeSelection,
            int cellBatchHint,
            long timestamp); @Override boolean shouldTriggerCompactions(); @Override ListenableFuture<Map<Cell, Value>> getAsync(TableReference tableRef, Map<Cell, Long> timestampByCell);  }