Examples with TraceContext com.google.gerrit.server.logging.TraceContext used on opensource projects

Example 1 with TraceContext

use of com.google.gerrit.server.logging.TraceContext in project gerrit by GerritCodeReview.

the class SshCommand method start.

@Override
public void start(ChannelSession channel, Environment env) throws IOException {
    startThread(() -> {
        try (DynamicOptions pluginOptions = new DynamicOptions(injector, dynamicBeans)) {
            parseCommandLine(pluginOptions);
            stdout = toPrintWriter(out);
            stderr = toPrintWriter(err);
            try (TraceContext traceContext = enableTracing();
                PerformanceLogContext performanceLogContext = new PerformanceLogContext(config, performanceLoggers)) {
                RequestInfo requestInfo = RequestInfo.builder(RequestInfo.RequestType.SSH, user, traceContext).build();
                try (RequestStateContext requestStateContext = RequestStateContext.open().addRequestStateProvider(deadlineCheckerFactory.create(requestInfo, deadline))) {
                    requestListeners.runEach(l -> l.onRequest(requestInfo));
                    SshCommand.this.run();
                } catch (InvalidDeadlineException e) {
                    stderr.println(e.getMessage());
                } catch (RuntimeException e) {
                    Optional<RequestCancelledException> requestCancelledException = RequestCancelledException.getFromCausalChain(e);
                    if (!requestCancelledException.isPresent()) {
                        Throwables.throwIfUnchecked(e);
                    }
                    cancellationMetrics.countCancelledRequest(requestInfo, requestCancelledException.get().getCancellationReason());
                    StringBuilder msg = new StringBuilder(requestCancelledException.get().formatCancellationReason());
                    if (requestCancelledException.get().getCancellationMessage().isPresent()) {
                        msg.append(String.format(" (%s)", requestCancelledException.get().getCancellationMessage().get()));
                    }
                    stderr.println(msg.toString());
                }
            } finally {
                stdout.flush();
                stderr.flush();
            }
        }
    }, AccessPath.SSH_COMMAND);
}

Example 2 with TraceContext

use of com.google.gerrit.server.logging.TraceContext in project gerrit by GerritCodeReview.

the class ReceiveCommits method sendMessages.

/**
 * Sends all messages which have been collected while processing the push to the client.
 *
 * <p><strong>Attention:</strong>{@link AsyncReceiveCommits} may call this method while {@link
 * #processCommands(Collection, MultiProgressMonitor)} is still running (if the execution of
 * processCommands takes too long and AsyncReceiveCommits gets a timeout). This means that local
 * variables that are accessed in this method must be thread-safe (otherwise we may hit a {@link
 * java.util.ConcurrentModificationException} if we read a variable here that at the same time is
 * updated by the background thread that still executes processCommands).
 */
void sendMessages() {
    try (TraceContext traceContext = TraceContext.newTrace(loggingTags.containsKey(RequestId.Type.TRACE_ID.name()), loggingTags.get(RequestId.Type.TRACE_ID.name()), (tagName, traceId) -> {
    })) {
        loggingTags.forEach((tagName, tagValue) -> traceContext.addTag(tagName, tagValue));
        for (ValidationMessage m : messages) {
            String msg = m.getType().getPrefix() + m.getMessage();
            logger.atFine().log("Sending message: %s", msg);
            // Avoid calling sendError which will add its own error: prefix.
            messageSender.sendMessage(msg);
        }
    }
}

Example 3 with TraceContext

use of com.google.gerrit.server.logging.TraceContext in project gerrit by GerritCodeReview.

the class ReceiveCommits method processCommands.

ReceiveCommitsResult processCommands(Collection<ReceiveCommand> commands, MultiProgressMonitor progress) throws StorageException {
    checkState(!used, "Tried to re-use a ReceiveCommits objects that is single-use only");
    long start = TimeUtil.nowNanos();
    parsePushOptions();
    String clientProvidedDeadlineValue = Iterables.getLast(pushOptions.get("deadline"), /* defaultValue= */
    null);
    int commandCount = commands.size();
    try (TraceContext traceContext = TraceContext.newTrace(tracePushOption.isPresent(), tracePushOption.orElse(null), (tagName, traceId) -> addMessage(tagName + ": " + traceId));
        PerformanceLogContext performanceLogContext = new PerformanceLogContext(config, performanceLoggers);
        TraceTimer traceTimer = newTimer("processCommands", Metadata.builder().resourceCount(commandCount))) {
        RequestInfo requestInfo = RequestInfo.builder(RequestInfo.RequestType.GIT_RECEIVE, user, traceContext).project(project.getNameKey()).build();
        requestListeners.runEach(l -> l.onRequest(requestInfo));
        traceContext.addTag(RequestId.Type.RECEIVE_ID, new RequestId(project.getNameKey().get()));
        // Log the push options here, rather than in parsePushOptions(), so that they are included
        // into the trace if tracing is enabled.
        logger.atFine().log("push options: %s", receivePack.getPushOptions());
        Task commandProgress = progress.beginSubTask("refs", UNKNOWN);
        commands = commands.stream().map(c -> wrapReceiveCommand(c, commandProgress)).collect(toList());
        try (RequestStateContext requestStateContext = RequestStateContext.open().addRequestStateProvider(progress).addRequestStateProvider(deadlineCheckerFactory.create(start, requestInfo, clientProvidedDeadlineValue))) {
            processCommandsUnsafe(commands, progress);
            rejectRemaining(commands, INTERNAL_SERVER_ERROR);
        } catch (InvalidDeadlineException e) {
            rejectRemaining(commands, e.getMessage());
        } catch (RuntimeException e) {
            Optional<RequestCancelledException> requestCancelledException = RequestCancelledException.getFromCausalChain(e);
            if (!requestCancelledException.isPresent()) {
                Throwables.throwIfUnchecked(e);
            }
            cancellationMetrics.countCancelledRequest(requestInfo, requestCancelledException.get().getCancellationReason());
            StringBuilder msg = new StringBuilder(requestCancelledException.get().formatCancellationReason());
            if (requestCancelledException.get().getCancellationMessage().isPresent()) {
                msg.append(String.format(" (%s)", requestCancelledException.get().getCancellationMessage().get()));
            }
            rejectRemaining(commands, msg.toString());
        }
        // This sends error messages before the 'done' string of the progress monitor is sent.
        // Currently, the test framework relies on this ordering to understand if pushes completed
        // successfully.
        sendErrorMessages();
        commandProgress.end();
        loggingTags = traceContext.getTags();
        logger.atFine().log("Processing commands done.");
    }
    progress.end();
    return result.build();
}

Example 4 with TraceContext

use of com.google.gerrit.server.logging.TraceContext in project gerrit by GerritCodeReview.

the class MergeOp method merge.

/**
 * Merges the given change.
 *
 * <p>Depending on the server configuration, more changes may be affected, e.g. by submission of a
 * topic or via superproject subscriptions. All affected changes are integrated using the projects
 * integration strategy.
 *
 * @param change the change to be merged.
 * @param caller the identity of the caller
 * @param checkSubmitRules whether the prolog submit rules should be evaluated
 * @param submitInput parameters regarding the merge
 * @throws RestApiException if an error occurred.
 * @throws PermissionBackendException if permissions can't be checked
 * @throws IOException an error occurred reading from NoteDb.
 * @return the merged change
 */
public Change merge(Change change, IdentifiedUser caller, boolean checkSubmitRules, SubmitInput submitInput, boolean dryrun) throws RestApiException, UpdateException, IOException, ConfigInvalidException, PermissionBackendException {
    this.submitInput = submitInput;
    this.notify = notifyResolver.resolve(firstNonNull(submitInput.notify, NotifyHandling.ALL), submitInput.notifyDetails);
    this.dryrun = dryrun;
    this.caller = caller;
    this.ts = TimeUtil.now();
    this.submissionId = new SubmissionId(change);
    try (TraceContext traceContext = TraceContext.open().addTag(RequestId.Type.SUBMISSION_ID, new RequestId(submissionId.toString()))) {
        openRepoManager();
        logger.atFine().log("Beginning integration of %s", change);
        try {
            ChangeSet indexBackedChangeSet = mergeSuperSet.setMergeOpRepoManager(orm).completeChangeSet(change, caller, /* includingTopicClosure= */
            false);
            if (!indexBackedChangeSet.ids().contains(change.getId())) {
                // indexBackedChangeSet contains only open changes, if the change is missing in this set
                // it might be that the change was concurrently submitted in the meantime.
                change = changeDataFactory.create(change).reloadChange();
                if (!change.isNew()) {
                    throw new ResourceConflictException("change is " + ChangeUtil.status(change));
                }
                throw new IllegalStateException(String.format("change %s missing from %s", change.getId(), indexBackedChangeSet));
            }
            if (indexBackedChangeSet.furtherHiddenChanges()) {
                throw new AuthException("A change to be submitted with " + change.getId() + " is not visible");
            }
            logger.atFine().log("Calculated to merge %s", indexBackedChangeSet);
            // Reload ChangeSet so that we don't rely on (potentially) stale index data for merging
            ChangeSet noteDbChangeSet = reloadChanges(indexBackedChangeSet);
            // At this point, any change that isn't new can be filtered out since they were only here
            // in the first place due to stale index.
            List<ChangeData> filteredChanges = new ArrayList<>();
            for (ChangeData changeData : noteDbChangeSet.changes()) {
                if (!changeData.change().getStatus().equals(Status.NEW)) {
                    logger.atFine().log("Change %s has status %s due to stale index, so it is skipped during submit", changeData.getId(), changeData.change().getStatus().name());
                    continue;
                }
                filteredChanges.add(changeData);
            }
            // There are no hidden changes (or else we would have thrown AuthException above).
            ChangeSet filteredNoteDbChangeSet = new ChangeSet(filteredChanges, /* hiddenChanges= */
            ImmutableList.of());
            // Count cross-project submissions outside of the retry loop. The chance of a single project
            // failing increases with the number of projects, so the failure count would be inflated if
            // this metric were incremented inside of integrateIntoHistory.
            int projects = filteredNoteDbChangeSet.projects().size();
            if (projects > 1) {
                topicMetrics.topicSubmissions.increment();
            }
            SubmissionExecutor submissionExecutor = new SubmissionExecutor(dryrun, superprojectUpdateSubmissionListeners);
            RetryTracker retryTracker = new RetryTracker();
            retryHelper.changeUpdate("integrateIntoHistory", updateFactory -> {
                long attempt = retryTracker.lastAttemptNumber + 1;
                boolean isRetry = attempt > 1;
                if (isRetry) {
                    logger.atFine().log("Retrying, attempt #%d; skipping merged changes", attempt);
                    this.ts = TimeUtil.now();
                    openRepoManager();
                }
                this.commitStatus = new CommitStatus(filteredNoteDbChangeSet, isRetry);
                if (checkSubmitRules) {
                    logger.atFine().log("Checking submit rules and state");
                    checkSubmitRulesAndState(filteredNoteDbChangeSet, isRetry);
                } else {
                    logger.atFine().log("Bypassing submit rules");
                    bypassSubmitRulesAndRequirements(filteredNoteDbChangeSet);
                }
                integrateIntoHistory(filteredNoteDbChangeSet, submissionExecutor);
                return null;
            }).listener(retryTracker).defaultTimeoutMultiplier(filteredNoteDbChangeSet.projects().size() * 2).retryOn(t -> t instanceof RuntimeException).call();
            submissionExecutor.afterExecutions(orm);
            if (projects > 1) {
                topicMetrics.topicSubmissionsCompleted.increment();
            }
            // (e.g. caller provided a change that was already merged).
            return updatedChanges.containsKey(change.getId()) ? updatedChanges.get(change.getId()) : change;
        } catch (IOException e) {
            // Anything before the merge attempt is an error
            throw new StorageException(e);
        }
    }
}

Example 5 with TraceContext

use of com.google.gerrit.server.logging.TraceContext in project gerrit by GerritCodeReview.

the class MergeSuperSet method completeChangeSetIncludingTopics.

private ChangeSet completeChangeSetIncludingTopics(ChangeSet changeSet, CurrentUser user) throws IOException, PermissionBackendException {
    Set<String> topicsSeen = new HashSet<>();
    Set<String> visibleTopicsSeen = new HashSet<>();
    int oldSeen;
    int seen;
    changeSet = topicClosure(changeSet, user, topicsSeen, visibleTopicsSeen);
    seen = topicsSeen.size() + visibleTopicsSeen.size();
    do {
        oldSeen = seen;
        try (TraceContext traceContext = PluginContext.newTrace(mergeSuperSetComputation)) {
            changeSet = mergeSuperSetComputation.get().completeWithoutTopic(orm, changeSet, user);
        }
        changeSet = topicClosure(changeSet, user, topicsSeen, visibleTopicsSeen);
        seen = topicsSeen.size() + visibleTopicsSeen.size();
    } while (seen != oldSeen);
    return changeSet;
}