Examples with Stopwatch com.google.common.base.Stopwatch used on opensource projects

Example 46 with Stopwatch

use of com.google.common.base.Stopwatch in project distributedlog by twitter.

the class TestAsyncReaderWriter method testAsyncWriteWithMinDelayBetweenFlushes.

@Test(timeout = 60000)
public void testAsyncWriteWithMinDelayBetweenFlushes() throws Exception {
    String name = "distrlog-asyncwrite-mindelay";
    DistributedLogConfiguration confLocal = new DistributedLogConfiguration();
    confLocal.loadConf(testConf);
    confLocal.setOutputBufferSize(0);
    confLocal.setImmediateFlushEnabled(true);
    confLocal.setMinDelayBetweenImmediateFlushMs(100);
    DistributedLogManager dlm = createNewDLM(confLocal, name);
    final Thread currentThread = Thread.currentThread();
    final int COUNT = 5000;
    final CountDownLatch syncLatch = new CountDownLatch(COUNT);
    int txid = 1;
    BKAsyncLogWriter writer = (BKAsyncLogWriter) (dlm.startAsyncLogSegmentNonPartitioned());
    Stopwatch executionTime = Stopwatch.createStarted();
    for (long i = 0; i < COUNT; i++) {
        Thread.sleep(1);
        final LogRecord record = DLMTestUtil.getLogRecordInstance(txid++);
        Future<DLSN> dlsnFuture = writer.write(record);
        dlsnFuture.addEventListener(new FutureEventListener<DLSN>() {

            @Override
            public void onSuccess(DLSN value) {
                syncLatch.countDown();
                LOG.debug("SyncLatch: {} ; DLSN: {} ", syncLatch.getCount(), value);
            }

            @Override
            public void onFailure(Throwable cause) {
                currentThread.interrupt();
            }
        });
    }
    boolean success = false;
    if (!(Thread.interrupted())) {
        try {
            success = syncLatch.await(10, TimeUnit.SECONDS);
        } catch (InterruptedException exc) {
            Thread.currentThread().interrupt();
        }
    }
    // Abort, not graceful close, since the latter will
    // flush as well, and may add an entry.
    writer.abort();
    executionTime.stop();
    assert (!(Thread.interrupted()));
    assert (success);
    LogRecordWithDLSN last = dlm.getLastLogRecord();
    LOG.info("Last Entry {}; elapsed time {}", last.getDlsn().getEntryId(), executionTime.elapsed(TimeUnit.MILLISECONDS));
    // Regardless of how many records we wrote; the number of BK entries should always be bounded by the min delay.
    // Since there are two flush processes--data flush and control flush, and since control flush may also end up flushing
    // data if data is available, the upper bound is 2*(time/min_delay + 1)
    assertTrue(last.getDlsn().getEntryId() <= ((executionTime.elapsed(TimeUnit.MILLISECONDS) / confLocal.getMinDelayBetweenImmediateFlushMs() + 1)) * 2);
    DLMTestUtil.verifyLogRecord(last);
    dlm.close();
}

Example 47 with Stopwatch

use of com.google.common.base.Stopwatch in project distributedlog by twitter.

the class MonitoredFuturePool method apply.

@Override
public <T> Future<T> apply(Function0<T> function0) {
    if (traceTaskExecution) {
        taskPendingCounter.inc();
        Stopwatch taskEnqueueStopwatch = Stopwatch.createStarted();
        Future<T> futureResult = futurePool.apply(new TimedFunction0<T>(function0));
        taskEnqueueTime.registerSuccessfulEvent(taskEnqueueStopwatch.elapsed(TimeUnit.MICROSECONDS));
        futureResult.ensure(new com.twitter.util.Function0<BoxedUnit>() {

            @Override
            public BoxedUnit apply() {
                taskPendingCounter.dec();
                return null;
            }
        });
        return futureResult;
    } else {
        return futurePool.apply(function0);
    }
}

Example 48 with Stopwatch

use of com.google.common.base.Stopwatch in project distributedlog by twitter.

the class BKLogHandler method asyncGetLedgerListInternal.

private void asyncGetLedgerListInternal(final Comparator<LogSegmentMetadata> comparator, final LogSegmentFilter segmentFilter, final Watcher watcher, final GenericCallback<List<LogSegmentMetadata>> finalCallback, final AtomicInteger numAttemptsLeft, final AtomicLong backoffMillis) {
    final Stopwatch stopwatch = Stopwatch.createStarted();
    try {
        if (LOG.isTraceEnabled()) {
            LOG.trace("Async getting ledger list for {}.", getFullyQualifiedName());
        }
        final GenericCallback<List<LogSegmentMetadata>> callback = new GenericCallback<List<LogSegmentMetadata>>() {

            @Override
            public void operationComplete(int rc, List<LogSegmentMetadata> result) {
                long elapsedMicros = stopwatch.stop().elapsed(TimeUnit.MICROSECONDS);
                if (KeeperException.Code.OK.intValue() != rc) {
                    getListStat.registerFailedEvent(elapsedMicros);
                } else {
                    if (LogSegmentFilter.DEFAULT_FILTER == segmentFilter) {
                        isFullListFetched.set(true);
                    }
                    getListStat.registerSuccessfulEvent(elapsedMicros);
                }
                finalCallback.operationComplete(rc, result);
            }
        };
        zooKeeperClient.get().getChildren(logMetadata.getLogSegmentsPath(), watcher, new AsyncCallback.Children2Callback() {

            @Override
            public void processResult(final int rc, final String path, final Object ctx, final List<String> children, final Stat stat) {
                if (KeeperException.Code.OK.intValue() != rc) {
                    if ((KeeperException.Code.CONNECTIONLOSS.intValue() == rc || KeeperException.Code.SESSIONEXPIRED.intValue() == rc || KeeperException.Code.SESSIONMOVED.intValue() == rc) && numAttemptsLeft.decrementAndGet() > 0) {
                        long backoffMs = backoffMillis.get();
                        backoffMillis.set(Math.min(conf.getZKRetryBackoffMaxMillis(), 2 * backoffMs));
                        scheduler.schedule(new Runnable() {

                            @Override
                            public void run() {
                                asyncGetLedgerListInternal(comparator, segmentFilter, watcher, finalCallback, numAttemptsLeft, backoffMillis);
                            }
                        }, backoffMs, TimeUnit.MILLISECONDS);
                        return;
                    }
                    callback.operationComplete(rc, null);
                    return;
                }
                if (LOG.isTraceEnabled()) {
                    LOG.trace("Got ledger list from {} : {}", logMetadata.getLogSegmentsPath(), children);
                }
                ledgerListWatchSet.set(true);
                Set<String> segmentsReceived = new HashSet<String>();
                segmentsReceived.addAll(segmentFilter.filter(children));
                Set<String> segmentsAdded;
                final Set<String> removedSegments = Collections.synchronizedSet(new HashSet<String>());
                final Map<String, LogSegmentMetadata> addedSegments = Collections.synchronizedMap(new HashMap<String, LogSegmentMetadata>());
                Pair<Set<String>, Set<String>> segmentChanges = logSegmentCache.diff(segmentsReceived);
                segmentsAdded = segmentChanges.getLeft();
                removedSegments.addAll(segmentChanges.getRight());
                if (segmentsAdded.isEmpty()) {
                    if (LOG.isTraceEnabled()) {
                        LOG.trace("No segments added for {}.", getFullyQualifiedName());
                    }
                    // update the cache before fetch
                    logSegmentCache.update(removedSegments, addedSegments);
                    List<LogSegmentMetadata> segmentList;
                    try {
                        segmentList = getCachedLogSegments(comparator);
                    } catch (UnexpectedException e) {
                        callback.operationComplete(KeeperException.Code.DATAINCONSISTENCY.intValue(), null);
                        return;
                    }
                    callback.operationComplete(KeeperException.Code.OK.intValue(), segmentList);
                    notifyUpdatedLogSegments(segmentList);
                    if (!removedSegments.isEmpty()) {
                        notifyOnOperationComplete();
                    }
                    return;
                }
                final AtomicInteger numChildren = new AtomicInteger(segmentsAdded.size());
                final AtomicInteger numFailures = new AtomicInteger(0);
                for (final String segment : segmentsAdded) {
                    metadataStore.getLogSegment(logMetadata.getLogSegmentPath(segment)).addEventListener(new FutureEventListener<LogSegmentMetadata>() {

                        @Override
                        public void onSuccess(LogSegmentMetadata result) {
                            addedSegments.put(segment, result);
                            complete();
                        }

                        @Override
                        public void onFailure(Throwable cause) {
                            // 2. In progress segment has been completed => inprogress ZNode does not exist
                            if (cause instanceof KeeperException && KeeperException.Code.NONODE == ((KeeperException) cause).code()) {
                                removedSegments.add(segment);
                                complete();
                            } else {
                                // fail fast
                                if (1 == numFailures.incrementAndGet()) {
                                    int rcToReturn = KeeperException.Code.SYSTEMERROR.intValue();
                                    if (cause instanceof KeeperException) {
                                        rcToReturn = ((KeeperException) cause).code().intValue();
                                    } else if (cause instanceof ZKException) {
                                        rcToReturn = ((ZKException) cause).getKeeperExceptionCode().intValue();
                                    }
                                    // :( properly we need dlog related response code.
                                    callback.operationComplete(rcToReturn, null);
                                    return;
                                }
                            }
                        }

                        private void complete() {
                            if (0 == numChildren.decrementAndGet() && numFailures.get() == 0) {
                                // update the cache only when fetch completed
                                logSegmentCache.update(removedSegments, addedSegments);
                                List<LogSegmentMetadata> segmentList;
                                try {
                                    segmentList = getCachedLogSegments(comparator);
                                } catch (UnexpectedException e) {
                                    callback.operationComplete(KeeperException.Code.DATAINCONSISTENCY.intValue(), null);
                                    return;
                                }
                                callback.operationComplete(KeeperException.Code.OK.intValue(), segmentList);
                                notifyUpdatedLogSegments(segmentList);
                                notifyOnOperationComplete();
                            }
                        }
                    });
                }
            }
        }, null);
    } catch (ZooKeeperClient.ZooKeeperConnectionException e) {
        getListStat.registerFailedEvent(stopwatch.stop().elapsed(TimeUnit.MICROSECONDS));
        finalCallback.operationComplete(KeeperException.Code.CONNECTIONLOSS.intValue(), null);
    } catch (InterruptedException e) {
        getListStat.registerFailedEvent(stopwatch.stop().elapsed(TimeUnit.MICROSECONDS));
        finalCallback.operationComplete(KeeperException.Code.CONNECTIONLOSS.intValue(), null);
    }
}

Example 49 with Stopwatch

use of com.google.common.base.Stopwatch in project distributedlog by twitter.

the class BKLogHandler method asyncGetLedgerList.

protected Future<List<LogSegmentMetadata>> asyncGetLedgerList(final boolean forceFetch, final boolean fetchFullList, final Comparator<LogSegmentMetadata> comparator, final boolean throwOnEmpty) {
    final Promise<List<LogSegmentMetadata>> promise = new Promise<List<LogSegmentMetadata>>();
    final Stopwatch stopwatch = Stopwatch.createStarted();
    final OpStatsLogger statsLogger = fetchFullList ? getFullListStat : getFilteredListStat;
    asyncDoGetLedgerList(forceFetch, fetchFullList, comparator, throwOnEmpty).addEventListener(new FutureEventListener<List<LogSegmentMetadata>>() {

        @Override
        public void onSuccess(List<LogSegmentMetadata> value) {
            statsLogger.registerSuccessfulEvent(stopwatch.stop().elapsed(TimeUnit.MICROSECONDS));
            promise.setValue(value);
        }

        @Override
        public void onFailure(Throwable cause) {
            statsLogger.registerFailedEvent(stopwatch.stop().elapsed(TimeUnit.MICROSECONDS));
            promise.setException(cause);
        }
    });
    return promise;
}

Example 50 with Stopwatch

use of com.google.common.base.Stopwatch in project distributedlog by twitter.

the class BKLogHandler method getLedgerList.

protected List<LogSegmentMetadata> getLedgerList(boolean forceFetch, boolean fetchFullList, Comparator<LogSegmentMetadata> comparator, boolean throwOnEmpty) throws IOException {
    Stopwatch stopwatch = Stopwatch.createStarted();
    boolean success = false;
    try {
        List<LogSegmentMetadata> segments = doGetLedgerList(forceFetch, fetchFullList, comparator, throwOnEmpty);
        success = true;
        return segments;
    } finally {
        OpStatsLogger statsLogger = fetchFullList ? getFullListStat : getFilteredListStat;
        if (success) {
            statsLogger.registerSuccessfulEvent(stopwatch.stop().elapsed(TimeUnit.MICROSECONDS));
        } else {
            statsLogger.registerFailedEvent(stopwatch.stop().elapsed(TimeUnit.MICROSECONDS));
        }
    }
}