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

Example 71 with Stopwatch

use of com.google.common.base.Stopwatch in project jackrabbit-oak by apache.

the class ClusterNodeInfo method renewLease.

/**
     * Renew the cluster id lease. This method needs to be called once in a while,
     * to ensure the same cluster id is not re-used by a different instance.
     * The lease is only renewed after 'leaseUpdateInterval' millis
     * since last lease update - default being every 10 sec (this used to be 30sec).
     * <p>
     * This method will not fail immediately with a DocumentStoreException if
     * the lease expired. It will still try to renew the lease and only fail if
     * {@link #performLeaseCheck()} decided the lease expired or another cluster
     * node initiated recover for this node.
     *
     * @return {@code true} if the lease was renewed; {@code false} otherwise.
     * @throws DocumentStoreException if the operation failed or the lease
     *          expired.
     */
public boolean renewLease() throws DocumentStoreException {
    long now = getCurrentTime();
    if (LOG.isTraceEnabled()) {
        LOG.trace("renewLease - leaseEndTime: " + leaseEndTime + ", leaseTime: " + leaseTime + ", leaseUpdateInterval: " + leaseUpdateInterval);
    }
    if (now < leaseEndTime - leaseTime + leaseUpdateInterval) {
        // no need to renew the lease - it is still within 'leaseUpdateInterval'
        return false;
    }
    // lease requires renewal
    long updatedLeaseEndTime;
    synchronized (this) {
        if (leaseCheckFailed) {
            // prevent lease renewal after it failed
            throw leaseExpired(LEASE_CHECK_FAILED_MSG, true);
        }
        // synchronized could have delayed the 'now', so
        // set it again..
        now = getCurrentTime();
        updatedLeaseEndTime = now + leaseTime;
    }
    UpdateOp update = new UpdateOp("" + id, false);
    update.set(LEASE_END_KEY, updatedLeaseEndTime);
    update.set(STATE, ACTIVE.name());
    if (renewed && !leaseCheckDisabled) {
        // if leaseCheckDisabled, then we just update the lease without
        // checking
        // OAK-3398:
        // if we renewed the lease ever with this instance/ClusterNodeInfo
        // (which is the normal case.. except for startup),
        // then we can now make an assertion that the lease is unchanged
        // and the incremental update must only succeed if no-one else
        // did a recover/inactivation in the meantime
        // make two assertions: the leaseEnd must match ..
        update.equals(LEASE_END_KEY, null, previousLeaseEndTime);
        // plus it must still be active ..
        update.equals(STATE, null, ACTIVE.name());
        // plus it must not have a recovery lock on it
        update.notEquals(REV_RECOVERY_LOCK, RecoverLockState.ACQUIRED.name());
    // @TODO: to make it 100% failure proof we could introduce
    // yet another field to clusterNodes: a runtimeId that we
    // create (UUID) at startup each time - and against that
    // we could also check here - but that goes a bit far IMO
    }
    if (LOG.isDebugEnabled()) {
        LOG.debug("Renewing lease for cluster id " + id + " with UpdateOp " + update);
    }
    Stopwatch sw = Stopwatch.createStarted();
    DocumentStoreException dse;
    Object result = null;
    try {
        ClusterNodeInfoDocument doc = store.findAndUpdate(Collection.CLUSTER_NODES, update);
        result = doc;
        if (doc == null) {
            synchronized (this) {
                if (leaseCheckFailed) {
                    // lease check failed - so we don't have to too - so we just log/throw
                    throw leaseExpired(LEASE_CHECK_FAILED_MSG, true);
                }
                // make sure only one thread 'wins', ie goes any further
                leaseCheckFailed = true;
            }
            String errorMsg = LEASE_CHECK_FAILED_MSG + " (Could not update lease anymore, someone else in the cluster " + "must have noticed this instance' slowness already. " + "Going to invoke leaseFailureHandler!)";
            // try to add more diagnostics
            try {
                ClusterNodeInfoDocument current = store.find(Collection.CLUSTER_NODES, "" + id);
                if (current != null) {
                    Object leaseEnd = current.get(LEASE_END_KEY);
                    Object recoveryLock = current.get(REV_RECOVERY_LOCK);
                    Object recoveryBy = current.get(REV_RECOVERY_BY);
                    Object cnState = current.get(STATE);
                    errorMsg += " (leaseEnd: " + leaseEnd + " (expected: " + leaseEndTime + ")" + ", (state: " + cnState + " (expected: " + ACTIVE.name() + ")" + ", recoveryLock: " + recoveryLock + ", recoveryBy: " + recoveryBy + ")";
                }
            } catch (DocumentStoreException ex) {
                LOG.error("trying to read ClusterNodeInfo for cluster id " + id, ex);
            }
            LOG.error(errorMsg);
            handleLeaseFailure(errorMsg);
            // should never be reached: handleLeaseFailure throws a DocumentStoreException
            return false;
        }
        leaseEndTime = updatedLeaseEndTime;
        // store previousLeaseEndTime for reference for next time
        previousLeaseEndTime = leaseEndTime;
        String mode = (String) doc.get(READ_WRITE_MODE_KEY);
        if (mode != null && !mode.equals(readWriteMode)) {
            readWriteMode = mode;
            store.setReadWriteMode(mode);
        }
        renewed = true;
        return true;
    } catch (DocumentStoreException e) {
        dse = e;
        result = e.toString();
    } finally {
        sw.stop();
        String msg = "Lease renewal for cluster id {} took {}, resulted in: {}";
        if (sw.elapsed(TimeUnit.SECONDS) > 10) {
            LOG.warn(msg, id, sw, result);
        } else if (sw.elapsed(TimeUnit.SECONDS) > 1) {
            LOG.info(msg, id, sw, result);
        } else if (LOG.isDebugEnabled()) {
            LOG.debug(msg, id, sw, result);
        }
    }
    // previousLeaseEndTime accordingly until leaseEndTime is reached
    while (getCurrentTime() < updatedLeaseEndTime) {
        synchronized (this) {
            if (leaseCheckFailed) {
                // no need to read from store, lease check already failed
                break;
            }
        }
        long t1 = clock.getTime();
        ClusterNodeInfoDocument doc;
        try {
            doc = store.find(Collection.CLUSTER_NODES, String.valueOf(id));
        } catch (DocumentStoreException e) {
            LOG.warn("Reading ClusterNodeInfoDocument for id " + id + " failed", e);
            // do not retry more than once a second
            try {
                clock.waitUntil(t1 + 1000);
            } catch (InterruptedException iex) {
            // ignore
            }
            continue;
        }
        if (doc != null) {
            if (!doc.isActive()) {
                LOG.warn("ClusterNodeInfoDocument for id {} is not active " + "anymore. {}", id, doc);
                // break here and let the next lease update attempt fail
                break;
            } else if (doc.getLeaseEndTime() == previousLeaseEndTime || doc.getLeaseEndTime() == updatedLeaseEndTime) {
                // set lease end times to current values
                previousLeaseEndTime = doc.getLeaseEndTime();
                leaseEndTime = doc.getLeaseEndTime();
                break;
            } else {
                // break here and let the next lease update attempt fail
                break;
            }
        } else {
            LOG.warn("ClusterNodeInfoDocument for id {} does not exist anymore", id);
            break;
        }
    }
    throw dse;
}

Example 72 with Stopwatch

use of com.google.common.base.Stopwatch in project jackrabbit-oak by apache.

the class IndexConsistencyChecker method check.

private Result check(Level level, boolean cleanWorkDir, Closer closer) throws IOException {
    Stopwatch watch = Stopwatch.createStarted();
    Result result = new Result();
    result.indexPath = indexPath;
    result.clean = true;
    result.watch = watch;
    log.info("[{}] Starting check", indexPath);
    checkBlobs(result);
    if (level == Level.FULL && result.clean) {
        checkIndex(result, closer);
    }
    if (result.clean) {
        log.info("[{}] No problems were detected with this index. Time taken {}", indexPath, watch);
    } else {
        log.warn("[{}] Problems detected with this index. Time taken {}", indexPath, watch);
    }
    if (cleanWorkDir) {
        FileUtils.deleteQuietly(workDir);
    } else if (workDir != null) {
        log.info("[{}] Index files are copied to {}", indexPath, workDir.getAbsolutePath());
    }
    watch.stop();
    return result;
}

Example 73 with Stopwatch

use of com.google.common.base.Stopwatch in project jackrabbit-oak by apache.

the class TarWriter method writeEntry.

private synchronized long writeEntry(UUID uuid, byte[] header, byte[] data, int offset, int size, int generation) throws IOException {
    checkState(!closed);
    if (access == null) {
        access = new RandomAccessFile(file, "rw");
        channel = access.getChannel();
    }
    long msb = uuid.getMostSignificantBits();
    long lsb = uuid.getLeastSignificantBits();
    int padding = getPaddingSize(size);
    long initialLength = access.getFilePointer();
    access.write(header);
    ioMonitor.beforeSegmentWrite(file, msb, lsb, size);
    Stopwatch stopwatch = Stopwatch.createStarted();
    access.write(data, offset, size);
    ioMonitor.afterSegmentWrite(file, msb, lsb, size, stopwatch.elapsed(TimeUnit.NANOSECONDS));
    if (padding > 0) {
        access.write(ZERO_BYTES, 0, padding);
    }
    long currentLength = access.getFilePointer();
    monitor.written(currentLength - initialLength);
    checkState(currentLength <= Integer.MAX_VALUE);
    TarEntry entry = new TarEntry(msb, lsb, (int) (currentLength - size - padding), size, generation);
    index.put(uuid, entry);
    return currentLength;
}

Example 74 with Stopwatch

use of com.google.common.base.Stopwatch in project jackrabbit-oak by apache.

the class DataStoreCheckCommand method retrieveBlobIds.

private static void retrieveBlobIds(GarbageCollectableBlobStore blobStore, File blob) throws Exception {
    System.out.println("Starting dump of blob ids");
    Stopwatch watch = createStarted();
    Iterator<String> blobIter = blobStore.getAllChunkIds(0);
    int count = writeStrings(blobIter, blob, true);
    sort(blob);
    System.out.println(count + " blob ids found");
    System.out.println("Finished in " + watch.elapsed(TimeUnit.SECONDS) + " seconds");
}

Example 75 with Stopwatch

use of com.google.common.base.Stopwatch in project jackrabbit-oak by apache.

the class DataStoreCheckCommand method checkConsistency.

private static void checkConsistency(File ids, File refs, File missing) throws IOException {
    System.out.println("Starting consistency check");
    Stopwatch watch = createStarted();
    FileLineDifferenceIterator iter = new FileLineDifferenceIterator(ids, refs, new Function<String, String>() {

        @Nullable
        @Override
        public String apply(@Nullable String input) {
            if (input != null) {
                return input.split(DELIM)[0];
            }
            return "";
        }
    });
    long candidates = writeStrings(iter, missing, true);
    System.out.println("Consistency check found " + candidates + " missing blobs");
    if (candidates > 0) {
        System.out.println("Consistency check failure for the data store");
    }
    System.out.println("Finished in " + watch.elapsed(TimeUnit.SECONDS) + " seconds");
}