Examples with StopWatch org.elasticsearch.common.StopWatch used on opensource projects

Example 16 with StopWatch

use of org.elasticsearch.common.StopWatch in project elasticsearch by elastic.

the class IndexAliasesIT method testSameAlias.

public void testSameAlias() throws Exception {
    logger.info("--> creating index [test]");
    assertAcked(prepareCreate("test").addMapping("type", "name", "type=text"));
    ensureGreen();
    logger.info("--> creating alias1 ");
    assertAcked((admin().indices().prepareAliases().addAlias("test", "alias1")));
    TimeValue timeout = TimeValue.timeValueSeconds(2);
    logger.info("--> recreating alias1 ");
    StopWatch stopWatch = new StopWatch();
    stopWatch.start();
    assertAcked((admin().indices().prepareAliases().addAlias("test", "alias1").setTimeout(timeout)));
    assertThat(stopWatch.stop().lastTaskTime().millis(), lessThan(timeout.millis()));
    logger.info("--> modifying alias1 to have a filter");
    stopWatch.start();
    assertAcked((admin().indices().prepareAliases().addAlias("test", "alias1", termQuery("name", "foo")).setTimeout(timeout)));
    assertThat(stopWatch.stop().lastTaskTime().millis(), lessThan(timeout.millis()));
    logger.info("--> recreating alias1 with the same filter");
    stopWatch.start();
    assertAcked((admin().indices().prepareAliases().addAlias("test", "alias1", termQuery("name", "foo")).setTimeout(timeout)));
    assertThat(stopWatch.stop().lastTaskTime().millis(), lessThan(timeout.millis()));
    logger.info("--> recreating alias1 with a different filter");
    stopWatch.start();
    assertAcked((admin().indices().prepareAliases().addAlias("test", "alias1", termQuery("name", "bar")).setTimeout(timeout)));
    assertThat(stopWatch.stop().lastTaskTime().millis(), lessThan(timeout.millis()));
    logger.info("--> verify that filter was updated");
    AliasMetaData aliasMetaData = ((AliasOrIndex.Alias) internalCluster().clusterService().state().metaData().getAliasAndIndexLookup().get("alias1")).getFirstAliasMetaData();
    assertThat(aliasMetaData.getFilter().toString(), equalTo("{\"term\":{\"name\":{\"value\":\"bar\",\"boost\":1.0}}}"));
    logger.info("--> deleting alias1");
    stopWatch.start();
    assertAcked((admin().indices().prepareAliases().removeAlias("test", "alias1").setTimeout(timeout)));
    assertThat(stopWatch.stop().lastTaskTime().millis(), lessThan(timeout.millis()));
}

Example 17 with StopWatch

use of org.elasticsearch.common.StopWatch in project crate by crate.

the class BlobRecoverySourceHandler method phase2.

/**
     * Perform phase2 of the recovery process
     * <p/>
     * Phase2 takes a snapshot of the current translog *without* acquiring the
     * write lock (however, the translog snapshot is a point-in-time view of
     * the translog). It then sends each translog operation to the target node
     * so it can be replayed into the new shard.
     */
public void phase2(Translog.Snapshot snapshot) {
    if (shard.state() == IndexShardState.CLOSED) {
        throw new IndexShardClosedException(request.shardId());
    }
    cancellableThreads.checkForCancel();
    StopWatch stopWatch = new StopWatch().start();
    logger.trace("{} recovery [phase2] to {}: sending transaction log operations", request.shardId(), request.targetNode());
    // Send all the snapshot's translog operations to the target
    int totalOperations = sendSnapshot(snapshot);
    stopWatch.stop();
    logger.trace("{} recovery [phase2] to {}: took [{}]", request.shardId(), request.targetNode(), stopWatch.totalTime());
    response.phase2Time = stopWatch.totalTime().millis();
    response.phase2Operations = totalOperations;
}

Example 18 with StopWatch

use of org.elasticsearch.common.StopWatch in project unipop by unipop-graph.

the class Misc method check.

private void check(Traversal traversal) {
    StopWatch sw = new StopWatch();
    int count = 0;
    sw.start();
    System.out.println("pre-strategy:" + traversal);
    traversal.hasNext();
    System.out.println("post-strategy:" + traversal);
    while (traversal.hasNext()) {
        count++;
        System.out.println(traversal.next());
    }
    sw.stop();
    System.out.println(sw.toString());
    System.out.println(count);
}

Example 19 with StopWatch

use of org.elasticsearch.common.StopWatch in project crate by crate.

the class ClusterApplierService method runTask.

private void runTask(UpdateTask task) {
    if (!lifecycle.started()) {
        LOGGER.debug("processing [{}]: ignoring, cluster applier service not started", task.source);
        return;
    }
    LOGGER.debug("processing [{}]: execute", task.source);
    final ClusterState previousClusterState = state.get();
    long startTimeMS = currentTimeInMillis();
    final StopWatch stopWatch = new StopWatch();
    final ClusterState newClusterState;
    try {
        try (Releasable ignored = stopWatch.timing("running task [" + task.source + ']')) {
            newClusterState = task.apply(previousClusterState);
        }
    } catch (Exception e) {
        TimeValue executionTime = TimeValue.timeValueMillis(Math.max(0, currentTimeInMillis() - startTimeMS));
        LOGGER.trace(() -> new ParameterizedMessage("failed to execute cluster state applier in [{}], state:\nversion [{}], source [{}]\n{}", executionTime, previousClusterState.version(), task.source, previousClusterState), e);
        warnAboutSlowTaskIfNeeded(executionTime, task.source, stopWatch);
        task.listener.onFailure(task.source, e);
        return;
    }
    if (previousClusterState == newClusterState) {
        TimeValue executionTime = TimeValue.timeValueMillis(Math.max(0, currentTimeInMillis() - startTimeMS));
        LOGGER.debug("processing [{}]: took [{}] no change in cluster state", task.source, executionTime);
        warnAboutSlowTaskIfNeeded(executionTime, task.source, stopWatch);
        task.listener.onSuccess(task.source);
    } else {
        if (LOGGER.isTraceEnabled()) {
            LOGGER.debug("cluster state updated, version [{}], source [{}]\n{}", newClusterState.version(), task.source, newClusterState);
        } else {
            LOGGER.debug("cluster state updated, version [{}], source [{}]", newClusterState.version(), task.source);
        }
        try {
            applyChanges(task, previousClusterState, newClusterState, stopWatch);
            TimeValue executionTime = TimeValue.timeValueMillis(Math.max(0, currentTimeInMillis() - startTimeMS));
            LOGGER.debug("processing [{}]: took [{}] done applying updated cluster state (version: {}, uuid: {})", task.source, executionTime, newClusterState.version(), newClusterState.stateUUID());
            warnAboutSlowTaskIfNeeded(executionTime, task.source, stopWatch);
            task.listener.onSuccess(task.source);
        } catch (Exception e) {
            TimeValue executionTime = TimeValue.timeValueMillis(Math.max(0, currentTimeInMillis() - startTimeMS));
            if (LOGGER.isTraceEnabled()) {
                LOGGER.warn(new ParameterizedMessage("failed to apply updated cluster state in [{}]:\nversion [{}], uuid [{}], source [{}]\n{}", executionTime, newClusterState.version(), newClusterState.stateUUID(), task.source, newClusterState), e);
            } else {
                LOGGER.warn(new ParameterizedMessage("failed to apply updated cluster state in [{}]:\nversion [{}], uuid [{}], source [{}]", executionTime, newClusterState.version(), newClusterState.stateUUID(), task.source), e);
            }
            // continue we will retry with the same cluster state but that might not help.
            assert applicationMayFail();
            task.listener.onFailure(task.source, e);
        }
    }
}

Example 20 with StopWatch

use of org.elasticsearch.common.StopWatch in project crate by crate.

the class RecoverySourceHandler method phase1.

/**
 * Perform phase1 of the recovery operations. Once this {@link IndexCommit}
 * snapshot has been performed no commit operations (files being fsync'd)
 * are effectively allowed on this index until all recovery phases are done
 * <p>
 * Phase1 examines the segment files on the target node and copies over the
 * segments that are missing. Only segments that have the same size and
 * checksum can be reused
 */
void phase1(IndexCommit snapshot, long startingSeqNo, IntSupplier translogOps, ActionListener<SendFileResult> listener) {
    cancellableThreads.checkForCancel();
    final Store store = shard.store();
    try {
        final StopWatch stopWatch = new StopWatch().start();
        final Store.MetadataSnapshot recoverySourceMetadata;
        try {
            recoverySourceMetadata = store.getMetadata(snapshot);
        } catch (CorruptIndexException | IndexFormatTooOldException | IndexFormatTooNewException ex) {
            shard.failShard("recovery", ex);
            throw ex;
        }
        for (String name : snapshot.getFileNames()) {
            final StoreFileMetadata md = recoverySourceMetadata.get(name);
            if (md == null) {
                logger.info("Snapshot differs from actual index for file: {} meta: {}", name, recoverySourceMetadata.asMap());
                throw new CorruptIndexException("Snapshot differs from actual index - maybe index was removed metadata has " + recoverySourceMetadata.asMap().size() + " files", name);
            }
        }
        if (canSkipPhase1(recoverySourceMetadata, request.metadataSnapshot()) == false) {
            final List<String> phase1FileNames = new ArrayList<>();
            final List<Long> phase1FileSizes = new ArrayList<>();
            final List<String> phase1ExistingFileNames = new ArrayList<>();
            final List<Long> phase1ExistingFileSizes = new ArrayList<>();
            // Total size of segment files that are recovered
            long totalSizeInBytes = 0;
            // Total size of segment files that were able to be re-used
            long existingTotalSizeInBytes = 0;
            // Generate a "diff" of all the identical, different, and missing
            // segment files on the target node, using the existing files on
            // the source node
            final Store.RecoveryDiff diff = recoverySourceMetadata.recoveryDiff(request.metadataSnapshot());
            for (StoreFileMetadata md : diff.identical) {
                phase1ExistingFileNames.add(md.name());
                phase1ExistingFileSizes.add(md.length());
                existingTotalSizeInBytes += md.length();
                if (logger.isTraceEnabled()) {
                    logger.trace("recovery [phase1]: not recovering [{}], exist in local store and has checksum [{}]," + " size [{}]", md.name(), md.checksum(), md.length());
                }
                totalSizeInBytes += md.length();
            }
            List<StoreFileMetadata> phase1Files = new ArrayList<>(diff.different.size() + diff.missing.size());
            phase1Files.addAll(diff.different);
            phase1Files.addAll(diff.missing);
            for (StoreFileMetadata md : phase1Files) {
                if (request.metadataSnapshot().asMap().containsKey(md.name())) {
                    logger.trace("recovery [phase1]: recovering [{}], exists in local store, but is different: remote [{}], local [{}]", md.name(), request.metadataSnapshot().asMap().get(md.name()), md);
                } else {
                    logger.trace("recovery [phase1]: recovering [{}], does not exist in remote", md.name());
                }
                phase1FileNames.add(md.name());
                phase1FileSizes.add(md.length());
                totalSizeInBytes += md.length();
            }
            logger.trace("recovery [phase1]: recovering_files [{}] with total_size [{}], reusing_files [{}] with total_size [{}]", phase1FileNames.size(), new ByteSizeValue(totalSizeInBytes), phase1ExistingFileNames.size(), new ByteSizeValue(existingTotalSizeInBytes));
            final StepListener<Void> sendFileInfoStep = new StepListener<>();
            final StepListener<Void> sendFilesStep = new StepListener<>();
            final StepListener<RetentionLease> createRetentionLeaseStep = new StepListener<>();
            final StepListener<Void> cleanFilesStep = new StepListener<>();
            cancellableThreads.checkForCancel();
            recoveryTarget.receiveFileInfo(phase1FileNames, phase1FileSizes, phase1ExistingFileNames, phase1ExistingFileSizes, translogOps.getAsInt(), sendFileInfoStep);
            sendFileInfoStep.whenComplete(r -> sendFiles(store, phase1Files.toArray(new StoreFileMetadata[0]), translogOps, sendFilesStep), listener::onFailure);
            sendFilesStep.whenComplete(r -> createRetentionLease(startingSeqNo, createRetentionLeaseStep), listener::onFailure);
            createRetentionLeaseStep.whenComplete(retentionLease -> {
                final long lastKnownGlobalCheckpoint = shard.getLastKnownGlobalCheckpoint();
                assert retentionLease == null || retentionLease.retainingSequenceNumber() - 1 <= lastKnownGlobalCheckpoint : retentionLease + " vs " + lastKnownGlobalCheckpoint;
                // Establishes new empty translog on the replica with global checkpoint set to lastKnownGlobalCheckpoint. We want
                // the commit we just copied to be a safe commit on the replica, so why not set the global checkpoint on the replica
                // to the max seqno of this commit? Because (in rare corner cases) this commit might not be a safe commit here on
                // the primary, and in these cases the max seqno would be too high to be valid as a global checkpoint.
                cleanFiles(store, recoverySourceMetadata, translogOps, lastKnownGlobalCheckpoint, cleanFilesStep);
            }, listener::onFailure);
            final long totalSize = totalSizeInBytes;
            final long existingTotalSize = existingTotalSizeInBytes;
            cleanFilesStep.whenComplete(r -> {
                final TimeValue took = stopWatch.totalTime();
                logger.trace("recovery [phase1]: took [{}]", took);
                listener.onResponse(new SendFileResult(phase1FileNames, phase1FileSizes, totalSize, phase1ExistingFileNames, phase1ExistingFileSizes, existingTotalSize, took));
            }, listener::onFailure);
        } else {
            logger.trace("skipping [phase1] since source and target have identical sync id [{}]", recoverySourceMetadata.getSyncId());
            // but we must still create a retention lease
            final StepListener<RetentionLease> createRetentionLeaseStep = new StepListener<>();
            createRetentionLease(startingSeqNo, createRetentionLeaseStep);
            createRetentionLeaseStep.whenComplete(retentionLease -> {
                final TimeValue took = stopWatch.totalTime();
                logger.trace("recovery [phase1]: took [{}]", took);
                listener.onResponse(new SendFileResult(Collections.emptyList(), Collections.emptyList(), 0L, Collections.emptyList(), Collections.emptyList(), 0L, took));
            }, listener::onFailure);
        }
    } catch (Exception e) {
        throw new RecoverFilesRecoveryException(request.shardId(), 0, new ByteSizeValue(0L), e);
    }
}