Examples with CompositeResult com.axway.ats.agent.core.templateactions.CompositeResult used on opensource projects

Example 1 with CompositeResult

use of com.axway.ats.agent.core.templateactions.CompositeResult in project ats-framework by Axway.

the class TemplateActionMethod method doInvoke.

/**
     * Invoke action and if needed return requested XPath entries as String[][]
     *
     */
@Override
protected Object doInvoke(Object instance, List<String> parameterNames, Object[] parameterValues) throws IllegalArgumentException, IllegalAccessException, InvocationTargetException, ActionExecutionException {
    if (log.isDebugEnabled()) {
        log.debug("Executing '" + actionName + "' with arguments " + StringUtils.methodInputArgumentsToString(parameterValues));
    }
    TemplateActionsResponseVerificationConfigurator responseVerificationConfigurator = (TemplateActionsResponseVerificationConfigurator) ThreadContext.getAttribute(ThreadContext.TEMPLATE_ACTION_VERIFICATION_CONFIGURATOR);
    String actionsXml = getActionsXml();
    //  insert any customer parameters into the thread scope map
    for (int iParameter = 0; iParameter < parameterNames.size(); iParameter++) {
        Object value = parameterValues[iParameter];
        // if the value is an object with more than one values, add them in a Queue
        if (value != null && (value instanceof Iterable || value.getClass().isArray())) {
            Queue<Object> queue = new LinkedList<Object>();
            if (value instanceof Iterable) {
                for (Object oneValue : (Iterable<?>) value) {
                    queue.add(oneValue);
                }
            } else {
                for (Object oneValue : (Object[]) value) {
                    queue.add(oneValue);
                }
            }
            value = queue;
        }
        ThreadContext.setAttribute(parameterNames.get(iParameter), value);
    }
    long actionStartTimestamp = -1;
    long totalTimeOfAllActionStepsNet = 0;
    long totalTimeOfAllActionStepsBetweenReqAndResp = 0;
    Object objectToReturn = null;
    String checkpointName;
    if (AbstractActionTask.REGISTER_FULL_AND_NET_ACTION_TIME_FOR_TEMPLATE_ACTIONS) {
        checkpointName = actionName + "-net";
    } else {
        checkpointName = actionName;
    }
    try {
        log.info("START running template actions from " + actionsXml);
        actionStartTimestamp = System.currentTimeMillis();
        if (isRegisterActionExecution() && !isLoggingInBatchMode) {
            autoLogger.startCheckpoint(checkpointName, "", actionStartTimestamp);
        }
        XmlReader xmlReader = new XmlReader(actionsXml);
        XmlUtilities xmlUtilities = new XmlUtilities();
        long xmlParsingTime = System.currentTimeMillis() - actionStartTimestamp;
        // this is the actual Action start time, skipping the actionXML parsing time
        actionStartTimestamp += xmlParsingTime;
        int actionNum = 1;
        long currentTimeOfActionStepRequest;
        NetworkingStopWatch stopWatch = new NetworkingStopWatch(actionMethodName);
        while (xmlReader.goToNextAction()) {
            String actionStep = actionMethodName + "[" + actionNum + "]";
            stopWatch.step0_SetNewContext(actionStep);
            String httpUrl = xmlReader.getRequestHttpUrl();
            String httpMethod = xmlReader.getRequestHttpMethod();
            List<ActionHeader> httpHeaders = xmlReader.getRequestHttpHeaders();
            // connect to the specified URL
            HttpClient httpClient = new HttpClient(httpUrl, httpMethod, httpHeaders, stopWatch);
            // send HTTP request
            String fileToSend = xmlReader.getRequestResourceFile();
            httpClient.sendHttpRequest(actionStep, fileToSend, xmlReader.hasParamsInRequestResourceFile());
            currentTimeOfActionStepRequest = stopWatch.getNetworkingTime();
            // Measure and log time between last data sent and start of receive.
            // Thread could be suspended but this could be server processing time too.
            // and log request time
            stopWatch.step5_StartInterimTimer();
            // read response
            ActionResponseObject expectedHttpResponseNode = xmlReader.getResponse();
            //                httpClient.disconnect(); // TODO: why this is needed. This is also before getting response
            if (xmlReader.isLastAction() && (wantedXpathEntries != null || returnResponseBodyAsString)) {
                if (returnResponseBodyAsString) {
                    // this is the last action and user wants to extract the response content as string
                    ActionParser actualHttpResponse = xmlUtilities.readActionResponse(httpClient, actionsXml, actionNum, true);
                    String contentAsString = actualHttpResponse.getBodyContentAsString();
                    actualHttpResponse.cleanupMembers();
                    objectToReturn = contentAsString;
                // log response time below and after that return result
                } else {
                    // this is the last action and user wants to extract some data from the response
                    ActionParser actualHttpResponse = xmlUtilities.readActionResponse(httpClient, actionsXml, actionNum, false);
                    String[][] extractedXpathEntries = XmlUtilities.extractXpathEntries(null, wantedXpathEntries);
                    actualHttpResponse.cleanupMembers();
                    objectToReturn = extractedXpathEntries;
                // log response time below and after that return result
                }
            } else {
                // verify the received response
                xmlUtilities.verifyResponse(actionsXml, actionMethodName, actionNum, expectedHttpResponseNode, httpClient, responseVerificationConfigurator);
            }
            long currentTimeOfActionStepEnd = stopWatch.getNetworkingTime();
            totalTimeOfAllActionStepsNet += currentTimeOfActionStepEnd;
            totalTimeOfAllActionStepsBetweenReqAndResp += stopWatch.getTimeBetweenReqAndResponse();
            if (HttpClient.logTimer.isTraceEnabled()) {
                HttpClient.logTimer.trace("This action step " + actionStep + " time between end of send request and start of getting response time took " + stopWatch.getTimeBetweenReqAndResponse() + " ms");
                HttpClient.logTimer.trace("This action step " + actionStep + " response network time took " + (currentTimeOfActionStepEnd - currentTimeOfActionStepRequest) + " ms");
                HttpClient.logTimer.trace("This action step " + actionStep + " total network time took " + currentTimeOfActionStepEnd + " ms");
            }
            actionNum++;
        }
        if (isRegisterActionExecution()) {
            if (HttpClient.logTimer.isTraceEnabled()) {
                HttpClient.logTimer.trace("\t    Total net time: " + totalTimeOfAllActionStepsNet + "(action " + actionsXml + ")| actionStartTimestamp : " + (actionStartTimestamp - xmlParsingTime) + "| total time between Req and Resp: " + totalTimeOfAllActionStepsBetweenReqAndResp);
            }
            if (isLoggingInBatchMode) {
                autoLogger.insertCheckpoint(checkpointName, actionStartTimestamp - xmlParsingTime, totalTimeOfAllActionStepsNet, 0L, /* transferSize */
                "", /* unit name */
                CheckpointResult.PASSED);
            } else {
                autoLogger.endCheckpoint(checkpointName, 0L, /* transferSize */
                CheckpointResult.PASSED, actionStartTimestamp - xmlParsingTime + /* the XML parsing time was previously added to the actionStartTimestamp (but after starting the Checkpoint) */
                totalTimeOfAllActionStepsNet);
            }
        }
        log.info("COMPLETE running template actions from " + actionsXml);
    } catch (Exception e) {
        if (isRegisterActionExecution()) {
            if (isLoggingInBatchMode) {
                autoLogger.insertCheckpoint(checkpointName, 0L, /* response time */
                CheckpointResult.FAILED);
            } else {
                autoLogger.endCheckpoint(checkpointName, 0L, /* transfer size */
                CheckpointResult.FAILED);
            }
        }
        throw new ActionExecutionException("Error executing a template action", e);
    }
    if (AbstractActionTask.REGISTER_FULL_AND_NET_ACTION_TIME_FOR_TEMPLATE_ACTIONS) {
        // Time between end of request and start of response reading - could be enabled only for some detailed investigations
        autoLogger.insertCheckpoint(actionName + "-betweenReqAndResp", actionStartTimestamp, totalTimeOfAllActionStepsBetweenReqAndResp, 0L, null, CheckpointResult.PASSED);
    }
    return new CompositeResult(objectToReturn, totalTimeOfAllActionStepsNet);
}

Example 2 with CompositeResult

use of com.axway.ats.agent.core.templateactions.CompositeResult in project ats-framework by Axway.

the class AbstractActionTask method invokeActions.

/**
     * Invoke one iteration of all actions in the queue
     * 
     * @throws InterruptedException
     */
protected final void invokeActions() throws InterruptedException {
    UserActionsMonitoringAgent userActionsMonitoringAgent = UserActionsMonitoringAgent.getInstance(caller);
    if (log.isDebugEnabled()) {
        log.debug("Starting '" + queueName + "' queue for " + (++nIterations) + "th time");
    }
    //generate the input arguments for all action invokers
    generateInputArguments();
    long queueDuration = 0;
    long actionStartTimestamp = 0;
    long actionEndTimestamp = 0;
    if (this.itManager != null) {
        // inform a new iteration is starting now
        this.itManager.setIterationStartTime(this, System.currentTimeMillis());
    }
    try {
        for (int i = 0; i < actionInvokers.size(); i++) {
            // start cycling all actions in this iteration
            ActionInvoker actionInvoker = actionInvokers.get(i);
            Object actionClassInstance = actionClassInstances.get(i);
            ActionMethod actionMethod = actionInvoker.getActionMethod();
            final String actionName = actionInvoker.getActionName();
            final String transferUnit = actionMethod.getTransferUnit();
            // read some settings
            final boolean registerActionExecution = actionMethod.isRegisterActionExecution();
            final boolean registerActionExecutionInQueueExecutionTime = actionMethod.isRegisterActionExecutionInQueueExecutionTime();
            final boolean isTemplateActionMethod = actionMethod instanceof TemplateActionMethod;
            final boolean logCheckpoints = !isTemplateActionMethod || REGISTER_FULL_AND_NET_ACTION_TIME_FOR_TEMPLATE_ACTIONS;
            // checkpoint name. For template actions by default only network time is tracked.
            // Here "-full" adds total action processing including XML (de)serializations, parameterization
            String checkpointName;
            if (!isTemplateActionMethod) {
                checkpointName = actionName;
            } else {
                checkpointName = actionName + "-full";
            }
            // start a checkpoint
            userActionsMonitoringAgent.actionStarted(actionName);
            if (registerActionExecution) {
                actionStartTimestamp = System.currentTimeMillis();
                if (logCheckpoints && !isLoggingInBatchMode) {
                    log.startCheckpoint(checkpointName, transferUnit, actionStartTimestamp);
                }
            }
            // invoke the current action
            Object actionReturnedResult = null;
            try {
                actionReturnedResult = actionInvoker.invoke(actionClassInstance);
            } catch (Exception e) {
                // the action failed - end the checkpoint
                if (registerActionExecution) {
                    if (logCheckpoints) {
                        if (isLoggingInBatchMode) {
                            log.insertCheckpoint(checkpointName, actionStartTimestamp, 0, 0, transferUnit, CheckpointResult.FAILED);
                        } else {
                            log.endCheckpoint(checkpointName, 0, CheckpointResult.FAILED);
                        }
                    }
                    QueueExecutionStatistics.getInstance().registerActionExecutionResult(queueName, actionName, false);
                }
                // re-throw the exception
                throw e;
            } finally {
                userActionsMonitoringAgent.actionEnded(actionName);
            }
            // the action passed
            if (registerActionExecution) {
                actionEndTimestamp = System.currentTimeMillis();
                long responseTimeMs = actionEndTimestamp - actionStartTimestamp;
                long transferSize = 0;
                if (transferUnit.length() > 0) {
                    transferSize = (Long) actionReturnedResult;
                }
                if (logCheckpoints) {
                    if (isLoggingInBatchMode) {
                        log.insertCheckpoint(checkpointName, actionStartTimestamp, responseTimeMs, transferSize, transferUnit, CheckpointResult.PASSED);
                    } else {
                        log.endCheckpoint(checkpointName, transferSize, CheckpointResult.PASSED, actionEndTimestamp);
                    }
                }
                if (registerActionExecutionInQueueExecutionTime) {
                    if (isTemplateActionMethod) {
                        // add net time in queue instead of full processing time
                        if (actionReturnedResult instanceof CompositeResult) {
                            CompositeResult res = (CompositeResult) actionReturnedResult;
                            responseTimeMs = res.getReqRespNetworkTime();
                        }
                    }
                    queueDuration += responseTimeMs;
                }
                QueueExecutionStatistics.getInstance().registerActionExecutionResult(queueName, actionName, true);
            }
        }
    // end cycling all actions in this iteration
    } catch (Exception e) {
        // We are particularly interested if the thread was interrupted
        Throwable cause = e.getCause();
        if (cause != null && cause instanceof InterruptedException) {
            // the thread was interrupted
            if (this.timedOut) {
                // the thread was interrupted due to timeout, log the timeout and go to next iteration
                log.error("Iteration timed out in " + this.timedOutSeconds + " seconds - skipping to next iteration");
                // reset our flag as we will start another iteration
                this.timedOut = false;
                this.timedOutSeconds = 0;
            } else {
                // the thread interrupted, but not due to timeout, maybe the user cancelled the queue
                this.externallyInterrupted = true;
                throw (InterruptedException) cause;
            }
        } else {
            // some kind of generic exception has occurred
            log.error("Exception caught during invocation - skipping to next iteration", e);
        }
        //continue to the next iteration
        return;
    } finally {
        if (this.itManager != null) {
            this.itManager.clearIterationStartTime();
        }
    }
    if (registerActionsInQueueExecutionTime) {
        log.insertCheckpoint(ATS_ACTION__QUEUE_EXECUTION_TIME, queueDuration, CheckpointResult.PASSED);
    }
}