Examples with ProfiledCall ru.fix.commons.profiler.ProfiledCall used on opensource projects

Example 1 with ProfiledCall

use of ru.fix.commons.profiler.ProfiledCall in project completable-reactor by ru-fix.

the class CompletableReactor method internalSubmit.

/**
 * Submit request without checking whether reactor closed or not.
 * If maxPendingRequestCount limit is reached prints error message and accepts request.
 *
 * @param payload
 * @param timeoutMs
 * @param <PayloadType>
 * @return
 */
private <PayloadType> Execution<PayloadType> internalSubmit(PayloadType payload, long timeoutMs) {
    if (pendingRequestCount.get() > maxPendingRequestCount.get()) {
        log.error("Max pending request count is reached. Request will be accepted but there is a possibility of " + "OOM or something wrong with back pressure logic in client code.\n" + "Use trySubmit method that supports back pressure or correctly handle the load on " + "CompletableReactor on client side.");
    }
    ProfiledCall payloadCall = profiler.profiledCall("" + ProfilerNames.PAYLOAD + "." + payload.getClass().getSimpleName()).start();
    ProfiledCall executionCall = profiler.profiledCall("" + ProfilerNames.EXECUTION + "." + payload.getClass().getSimpleName()).start();
    /**
     * Inline graph execution scenario
     */
    Function inlineGraphFunction = inlinePayloadGraphs.get(payload.getClass());
    if (inlineGraphFunction != null) {
        CompletableFuture<PayloadType> inlineGraphResult = (CompletableFuture<PayloadType>) inlineGraphFunction.apply(payload);
        inlineGraphResult.thenAcceptAsync(any -> {
            payloadCall.stop();
            executionCall.stop();
        });
        return new Execution<>(inlineGraphResult, inlineGraphResult.thenAccept(any -> {
        /* do nothing */
        }), null);
    }
    /**
     * Standard graph execution scenario
     */
    ReactorGraphExecution<PayloadType> execution;
    ReactorGraph<PayloadType> graph = payloadGraphs.get(payload.getClass());
    if (graph != null) {
        execution = executionBuilder.build(graph);
    } else {
        GlGraph glGraph = glPayloadGraphs.get(payload.getClass());
        if (glGraph != null) {
            execution = glExecutionBuilder.build(glGraph);
        } else {
            throw new IllegalArgumentException(String.format("Rector graph not found for payload %s", payload.getClass()));
        }
    }
    /**
     * Handling pending request counts
     */
    pendingRequestCount.incrementAndGet();
    PayloadStatCounters statistics = payloadStatCounters.computeIfAbsent(payload.getClass(), key -> new PayloadStatCounters());
    statistics.runningTotal.increment();
    execution.getChainExecutionFuture().handleAsync((result, thr) -> {
        statistics.runningTotal.decrement();
        return null;
    });
    execution.getResultFuture().handleAsync((result, thr) -> {
        statistics.runningWithoutResult.decrement();
        return null;
    });
    /**
     * Launching chain execution
     */
    execution.getSubmitFuture().complete(payload);
    // TODO: add to exception details about vertex statuses, what vertix is currently does not completed on time
    /**
     * Add timeout protection to execution
     */
    ScheduledFuture<?> schedule = timeoutExecutorService.schedule(() -> {
        /**
         * Temporary solution.
         * Should be fixed by completing all futures in processor chain
         */
        if (!execution.getResultFuture().isDone()) {
            execution.getResultFuture().completeExceptionally(new TimeoutException(String.format("Response for payload %s took more than %d ms.", payload, timeoutMs)));
        }
        if (!execution.getChainExecutionFuture().isDone()) {
            execution.getChainExecutionFuture().completeExceptionally(new TimeoutException(String.format("Execution of payload %s took more than %d ms.", payload, timeoutMs)));
        }
    }, timeoutMs, TimeUnit.MILLISECONDS);
    execution.getChainExecutionFuture().handleAsync((result, throwable) -> {
        long count = pendingRequestCount.decrementAndGet();
        if (count == 0) {
            synchronized (pendingRequestCount) {
                pendingRequestCount.notifyAll();
            }
        }
        schedule.cancel(false);
        return null;
    });
    execution.getResultFuture().thenRunAsync(payloadCall::stop);
    execution.getChainExecutionFuture().thenRunAsync(executionCall::stop);
    return new Execution<>(execution.getResultFuture(), execution.getChainExecutionFuture(), execution.getDebugProcessingVertexGraphState());
}

Example 2 with ProfiledCall

use of ru.fix.commons.profiler.ProfiledCall in project completable-reactor by ru-fix.

the class ReactorGraphExecutionBuilder method merge.

/**
 * @param processingVertex
 * @param processorResult       empty in case of detached merge point
 * @param payload
 * @param executionResultFuture
 * @param <PayloadType>
 */
private <PayloadType> void merge(ProcessingVertex processingVertex, Object processorResult, Object payload, CompletableFuture<PayloadType> executionResultFuture) {
    CRReactorGraph.ProcessingItemInfo processorInfo = processingVertex.getProcessingItemInfo();
    Supplier<Enum> mergerInvocation;
    switch(processorInfo.getProcessingItemType()) {
        case PROCESSOR:
            if (processorInfo.getDescription().getMerger() == null) {
                /**
                 * This Processor does not have merger
                 */
                processingVertex.getMergePointFuture().complete(new MergePayloadContext().setDeadTransition(true));
                return;
            } else {
                mergerInvocation = () -> (Enum) processorInfo.getDescription().getMerger().merge(payload, processorResult);
            }
            break;
        case SUBGRAPH:
            if (processorInfo.getSubgraphDescription().getMerger() == null) {
                /**
                 * This Subgraph does not have merger
                 */
                processingVertex.getMergePointFuture().complete(new MergePayloadContext().setDeadTransition(true));
                return;
            } else {
                mergerInvocation = () -> (Enum) processorInfo.getSubgraphDescription().getMerger().merge(payload, processorResult);
            }
            break;
        case MERGE_POINT:
            mergerInvocation = () -> (Enum) processorInfo.getDetachedMergePointDescription().getMerger().merge(payload);
            break;
        default:
            throw new IllegalArgumentException(String.format("Unknown processor type: %s", processorInfo.getProcessingItemType()));
    }
    try {
        ProfiledCall mergeCall = profiler.profiledCall(ProfilerNames.MERGE + "." + (payload != null ? payload.getClass().getSimpleName() : "null") + "." + processingVertex.getProcessingItem().getProfilingName()).start();
        boolean isTraceablePayload = tracer.isTraceable(payload);
        Object mergeTracingMarker = isTraceablePayload ? tracer.beforeMerge(processingVertex.getProcessingItem().getIdentity().toString(), payload, processorResult) : null;
        Enum mergeStatus = mergerInvocation.get();
        mergeCall.stop();
        if (isTraceablePayload) {
            tracer.afterMerger(mergeTracingMarker, processingVertex.getProcessingItem().getIdentity().toString(), payload);
        }
        /**
         * Select outgoing transitions that matches mergeStatus
         */
        List<CRReactorGraph.Transition> activeTransitions = processingVertex.getMergePointTransition().stream().filter(transition -> transition.isOnAny() || transition.getMergeStatuses().contains(mergeStatus)).collect(Collectors.toList());
        if (activeTransitions.size() <= 0) {
            throw new IllegalStateException(String.format("Merger function returned %s.%s status." + " But merge point of processor %s does not have matching transition for this status." + " Expected status from merger function one of: %s", mergeStatus.getDeclaringClass(), mergeStatus, processingVertex.getProcessingItem().getDebugName(), processingVertex.getMergePointTransition().stream().map(CRReactorGraph.Transition::getDebugDescription).collect(Collectors.joining(",", "{", "}"))));
        }
        /**
         * check if this merge point have terminal transitions that matches merge status
         */
        if (activeTransitions.stream().anyMatch(CRReactorGraph.Transition::isComplete)) {
            /**
             * Handle terminal transition by completing execution result
             */
            if (!executionResultFuture.complete((PayloadType) payload)) {
                Object previousResult = null;
                try {
                    if (executionResultFuture.isDone()) {
                        previousResult = executionResultFuture.get();
                    } else {
                        log.error("Illegal graph execution state." + " Completion failed for new result," + " but execution result from previous terminal step is not complete.");
                    }
                } catch (Exception exc) {
                    log.error("Failed to get completed execution result from previous terminal step.", exc);
                }
                log.error("Processing chain was completed by at least two different terminal steps." + " Already completed with result {}." + " New completion result {} in merge point for processor {}", debugSerializer.dumpObject(previousResult), debugSerializer.dumpObject(payload), processingVertex.getProcessingItem().getDebugName());
            }
            /**
             * Terminal state reached. Execution result completed.
             * Throw poison pill - terminal context. All following merge points should be deactivated.
             */
            processingVertex.getMergePointFuture().complete(new MergePayloadContext().setPayload(null).setMergeResult(mergeStatus).setTerminal(true));
        } else {
            /**
             * There is no terminal state reached after merging.
             */
            processingVertex.getMergePointFuture().complete(new MergePayloadContext().setPayload(payload).setMergeResult(mergeStatus));
        }
    } catch (Exception exc) {
        log.error("Failed to merge payload {} {} by processing item {} for result {}", payload.getClass(), debugSerializer.dumpObject(payload), processingVertex.getProcessingItem().getDebugName(), debugSerializer.dumpObject(processorResult), exc);
        executionResultFuture.completeExceptionally(exc);
        processingVertex.getMergePointFuture().complete(new MergePayloadContext().setDeadTransition(true));
    }
}

Example 3 with ProfiledCall

use of ru.fix.commons.profiler.ProfiledCall in project completable-reactor by ru-fix.

the class ReactorGraphExecutionBuilder method handle.

private <PayloadType> void handle(ProcessingVertex processingVertex, TransitionPayloadContext payloadContext, CompletableFuture<PayloadType> executionResultFuture) {
    CRReactorGraph.ProcessingItemInfo processorInfo = processingVertex.getProcessingItemInfo();
    Object payload = payloadContext.getPayload();
    /**
     * In case of detached merge point processor should not have incoming handling transition.
     */
    if (processorInfo.getProcessingItemType() == CRReactorGraph.ProcessingItemType.MERGE_POINT) {
        throw new IllegalStateException(String.format("Processor %s is of type %s and should not have any incoming handling transition", processingVertex.getProcessingItem().getDebugName(), processorInfo.getProcessingItemType()));
    }
    ProfiledCall handleCall = profiler.profiledCall(ProfilerNames.HANDLE + "." + (payload != null ? payload.getClass().getSimpleName() : "null") + "." + processingVertex.getProcessingItem().getProfilingName()).start();
    boolean isTraceablePayload = tracer.isTraceable(payload);
    Object handleTracingMarker = isTraceablePayload ? tracer.beforeHandle(processingVertex.getProcessingItem().getIdentity().toString(), payload) : null;
    ReactorGraphModel.Identity handleTracingIdentity = isTraceablePayload ? processingVertex.getProcessingItem().getIdentity() : null;
    CompletableFuture<?> handlingResult;
    /**
     * Immutability check ensures that there is no payload modification during handling.
     */
    final ImmutabilityControlLevel controlLevel = this.immutabilityControlLevel;
    ImmutabilityChecker.Snapshot payloadSnapshot;
    try {
        if (controlLevel != ImmutabilityControlLevel.NO_CONTROL) {
            /**
             * Invoke handling with immutability check.
             */
            payloadSnapshot = immutabilityChecker.takeSnapshot(payload);
            handlingResult = invokeHandlingMethod(processorInfo, processingVertex.getProcessingItem(), payload);
        } else {
            /**
             * Invoke handling without immutability check.
             */
            payloadSnapshot = null;
            handlingResult = invokeHandlingMethod(processorInfo, processingVertex.getProcessingItem(), payload);
        }
    } catch (Exception handlingException) {
        RuntimeException exc = new RuntimeException(String.format("Failed handling by processor %s for payload %s %s. Handling method raised exception: %s.", processingVertex.getProcessingItem().getDebugName(), payload.getClass(), debugSerializer.dumpObject(payload), handlingException), handlingException);
        log.error(exc.getMessage(), exc);
        executionResultFuture.completeExceptionally(exc);
        processingVertex.getProcessorFuture().complete(new HandlePayloadContext().setTerminal(true));
        return;
    }
    if (handlingResult == null) {
        RuntimeException exc = new RuntimeException(String.format("Failed handling by processor %s for payload %s %s. Handling method returned NULL." + " Instance of CompletableFuture expected.", processingVertex.getProcessingItem().getDebugName(), payload.getClass(), debugSerializer.dumpObject(payload)));
        log.error(exc.getMessage(), exc);
        executionResultFuture.completeExceptionally(exc);
        processingVertex.getProcessorFuture().complete(new HandlePayloadContext().setTerminal(true));
        return;
    }
    handlingResult.handleAsync((res, thr) -> {
        handleCall.stop();
        if (isTraceablePayload) {
            tracer.afterHandle(handleTracingMarker, handleTracingIdentity.toString(), res, thr);
        }
        if (controlLevel != ImmutabilityControlLevel.NO_CONTROL) {
            Optional<String> diff = immutabilityChecker.diff(payloadSnapshot, payload);
            if (diff.isPresent()) {
                String message = String.format("Concurrent modification of payload %s detected. Diff: %s.", debugSerializer.dumpObject(payload), diff.get());
                switch(controlLevel) {
                    case LOG_ERROR:
                        log.error(message);
                        break;
                    case LOG_WARN:
                        log.warn(message);
                        break;
                    case EXCEPTION:
                        RuntimeException immutabilityException = new RuntimeException(message);
                        log.error(message, immutabilityException);
                        if (thr == null) {
                            log.error("Overwriting execution exception {} by immutability check exception {}.", thr, immutabilityException, thr);
                        }
                        thr = immutabilityException;
                        break;
                }
            }
        }
        if (thr != null) {
            RuntimeException exc = new RuntimeException(String.format("Failed handling by processor %s for payload %s %s", processingVertex.getProcessingItem().getDebugName(), payload.getClass(), debugSerializer.dumpObject(payload)), thr);
            log.error(exc.getMessage(), exc);
            executionResultFuture.completeExceptionally(exc);
            processingVertex.getProcessorFuture().complete(new HandlePayloadContext().setTerminal(true));
        } else {
            processingVertex.getProcessorFuture().complete(new HandlePayloadContext().setPayload(payload).setProcessorResult(res));
        }
        return null;
    }).exceptionally(exc -> {
        log.error("Failed to execute afterHandle block for {}", Optional.of(processingVertex).map(ProcessingVertex::getProcessingItem).map(CRProcessingItem::getDebugName).orElse("?"), exc);
        return null;
    });
}

Example 4 with ProfiledCall

use of ru.fix.commons.profiler.ProfiledCall in project completable-reactor by ru-fix.

the class GlProfilingTest method trace_payload_if_payload_contain_special_id.

@Test
public void trace_payload_if_payload_contain_special_id() throws Exception {
    Profiler profiler = mock(Profiler.class);
    ProfiledCall profiledCall = mock(ProfiledCall.class);
    when(profiler.profiledCall(any())).thenReturn(profiledCall);
    when(profiledCall.start()).thenReturn(profiledCall);
    final CompletableReactor completableReactor = new CompletableReactor(profiler);
    SimpleGraph graph = new SimpleGraph();
    completableReactor.registerGraph(graph);
    for (int num = 0; num < 10; num++) {
        completableReactor.submit(new TracablePayload().setNumber(num));
    }
    completableReactor.close();
    verify(profiler, times(80)).profiledCall(any());
    verify(profiler, times(10)).profiledCall(prefix(ProfilerNames.PAYLOAD));
    verify(profiler, times(10)).profiledCall(prefix(ProfilerNames.EXECUTION));
    verify(profiler, times(10)).profiledCall(prefix(ProfilerNames.HANDLE) + ".processor1");
    verify(profiler, times(10)).profiledCall(prefix(ProfilerNames.HANDLE) + ".processor2");
    verify(profiler, times(10)).profiledCall(prefix(ProfilerNames.HANDLE) + ".processor3");
    verify(profiler, times(10)).profiledCall(prefix(ProfilerNames.MERGE) + ".processor1");
    verify(profiler, times(10)).profiledCall(prefix(ProfilerNames.MERGE) + ".processor2");
    verify(profiler, times(10)).profiledCall(prefix(ProfilerNames.MERGE) + ".processor3");
}