reportportal / agent-java-karate

Karate integration for ReportPortal
Apache License 2.0
10 stars 16 forks source link

Karate 1.3.1 support #17

Closed vrymar closed 12 months ago

DzmitryHumianiuk commented 1 year ago

@vrymar @vitaliirymar thanks for the contribution!

vrymar commented 1 year ago

Commented the following in build.gradle due to blocking issue for gradle version >=7.0: https://github.com/reportportal/gradle-scripts/issues/37 //apply from: "${project.scripts_url}/${project.scripts_branch}/release-commons.gradle" //apply from: "${project.scripts_url}/${project.scripts_branch}/build-quality.gradle" //apply from: "${project.scripts_url}/${project.scripts_branch}/signing.gradle"

vrymar commented 1 year ago

Faced an issue with the nested steps feature – the steps order is mixed up: image image

DzmitryHumianiuk commented 1 year ago

@vrymar could you please check what is the starttime value for each of the steps/logs represented in this example?

vitaliirymar commented 1 year ago

@vrymar could you please check what is the starttime value for each of the steps/logs represented in this example? It is the same image

DzmitryHumianiuk commented 1 year ago

@vrymar, this is what I'm referring to: open the Network calls, take a look at the startTime of each returned line of logs/steps. If they are equal and belong to the same "second" in milliseconds (like what you've shown in your screenshot at 18:58:26) and on, the only sorting mechanism available for us is the sequence of processing of requests in the queue by the API itself.

I mean, the date 2023-07-20 18:58:28 is 1689893906 seconds in Unix timestamp. this is: 1689893906 seconds 1689893906000 milliseconds.

if all timestamps of your items in returned logs are equal 1689893906000 (or anything between 1689893906000 and 1689893906999) than it should be fixed on the framework side.

To address this, your testing framework should be able to send timestamps with millisecond precision. This will differentiate the log/steps entries and provide a more accurate sequence.

image
vrymar commented 1 year ago

Hi @DzmitryHumianiuk ! Thanks! Some of the steps have the same startTime. Now I'm a bit confused on the workflow. In this repo startFeature and finishFeature is triggered from the KarateReportPortalSuite class, onFeatureDone method , then all the received data is manipulated in a separate ReportPortalPublisher class, where startScenario, finishScenario, startStep and finishStep are implemented and results are published to RP. Questions:

  1. startStep method includes setStartTime which adds Date, which is not the Karate step date. How can I provide the date from Karate step? Note: I've checked other RP agents as example and the Date setter is the same.
    private void startStep(StepResult stepResult) {
        StartTestItemRQ rq = new StartTestItemRQ();
        rq.setName(stepResult.getStep().getPrefix() + " " + stepResult.getStep().getText());
        **rq.setStartTime(Calendar.getInstance().getTime());**
        rq.setType("STEP");
        rq.setHasStats(false);
        stepId = launch.get().getStepReporter().startNestedStep(rq);
    }
  2. Looks like steps are generated and published very fast (within milliseconds) as implemented in the following method. Can it be the cause of the issue? How can it be overcome?

    private void sendStepResults(List<StepResult> stepResults) {
        for (StepResult stepResult : stepResults) {
            **startStep(stepResult);**
            Result result = stepResult.getResult();
            String logLevel = getLogLevel(result.getStatus());
            Step step = stepResult.getStep();
    
            if (step.getDocString() != null) {
                sendLog("\n-----------------DOC_STRING-----------------\n" + step.getDocString(), logLevel);
            }
    
            if (stepResult.getStepLog() != null
                    && !stepResult.getStepLog().isEmpty()
                    && !stepResult.getStepLog().equals(" ")) {
                sendLog(stepResult.getStepLog(), logLevel);
            }
    
            **finishStep(stepResult);**
        }
    }
HardNorth commented 1 year ago

@vrymar,

  1. If Karate itself does not provide you that Date, then there is nothing you can do, just set Date on the moment of reporting. Actually, I can't recall a framework which really does that, so that why we set our Date everywhere.
  2. This is certainly the cause. Well, first, ask yourself, do you really need to overcome it? If so, then there are some options. E.G. you can create a ConcurrentHashMap for each parent item with an AtomicLong representing the last step time, and if it's equal or greater than current one use it, add 1 millisecond and save it.
DzmitryHumianiuk commented 1 year ago

@HardNorth @vrymar and it looks like this is a valid point to raise with the Karate team. We should ask them if they can provide a startTime and endTime on their end.

DzmitryHumianiuk commented 1 year ago

@vrymar @HardNorth looks like we got it on the Karate side: https://github.com/karatelabs/karate/commit/30e93ed95e54d53b81a2a760a61aa1ad220cb55b

DzmitryHumianiuk commented 1 year ago

@vitaliirymar @vrymar well, at least we have it now for the upcoming versions of Karate, but we will miss it for the vast majority of actual and actively used versions.

Thus, I assume that it makes sense to add a workaround to include the startTime on our end with ConcurrentHashMap if Karate doesn't return it, and use Karate's data if it does.

vrymar commented 1 year ago

Workaround was applied ( ConcurrentHashMap for each step item with an AtomicLong representing the last step time ). Step startTime and endTime will be provided by Karate in v1.4.1 https://github.com/karatelabs/karate/commit/30e93ed95e54d53b81a2a760a61aa1ad220cb55b Then the agent can be modified to fit the new data provided by Karate.

HardNorth commented 1 year ago

@vrymar Thank you! But if you use ConcurrentHashMap you don't need AtomicLong, it's over synchronizing.

vrymar commented 1 year ago

Hi @HardNorth ! Right. Fixed. Also removed extra logging. https://github.com/reportportal/agent-java-karate/pull/17/commits/d9f2c94feeb162f154c76eefd55a75323bc45ade

DzmitryHumianiuk commented 1 year ago

@vrymar, @vitaliirymar, what if we make the startTime feature more flexible, regardless of the version of Karate being used?

It would be like implementing a try-catch wrapper:

This approach would ensure compatibility with any version of Karate, whether or not they have a fix for startTime in the available version.

@HardNorth, @vrymar, @vitaliirymar, what are your thoughts?

vrymar commented 1 year ago

@DzmitryHumianiuk , the idea is great. I tried it before, but failed. According to the Karate fix in 1.4.1, there will be a new method getStartTime in StepResult class. Now the method is absent in Karate 1.3.1, thus, the method reference fails during compilation.

DzmitryHumianiuk commented 1 year ago

@vrymar you can try this by using reflection, which enables you to examine and modify the runtime behavior of a class. With reflection, you can dynamically load the class and invoke the method only if it's available. This avoids the compilation error since you won't be making a direct call to the method.

public Date getStartTime() {
    try {
        Class<?> classik = Class.forName("com.Karate.Class");
        // Check if the method exists (will return in case if this is 1.4.1+)
        Method method = classik.getMethod("getStartTime"); 
        // Create an instance of the class or use existing instance if provided.
        Object instance = classik.getDeclaredConstructor().newInstance(); 
        // Invoke the method if available
        return (Date) method.invoke(instance);         
    } catch (ClassNotFoundException | NoSuchMethodException | IllegalAccessException | InvocationTargetException | InstantiationException e) {
        // If class or method not found or any other exception occurs, use your own method to generate the time
        return myOwnMethodToGenerateTime();
    }
}

private Date myOwnMethodToGenerateTime() {
    // Your logic to generate time
}
vrymar commented 1 year ago

@DzmitryHumianiuk , thanks for the great idea! Will check that and try it out.

vrymar commented 1 year ago

@DzmitryHumianiuk , @HardNorth, I've faced an issue with startTime values provided by Karate. Scenario:

  1. Take latest Karate version with step startTime fix: 1.4.1.RC3
  2. Execute the test with the agent with direct Karate method reference: stepResult.getResult().getStartTime() Result: Step order is incorrect. It is related to the Skipped steps, because they are executed within the same millisec. Passed or Failed steps took more time and their order is correct. See screenshot, where the first 2 steps are Passed and Failed correspondingly. 2023-08-29 13_01_28-ah-phoenix-karate-framework-example – ScenarioRunnerTest java

Conclusions:

DzmitryHumianiuk commented 1 year ago

@vrymar we can kindly ask the Karate team to include this feature for scenarios, suites, and various levels.

And I believe it makes sense to keep our workaround in place for the time being, even if Karate starts providing this information. This will ensure that we're on the safe side.

vrymar commented 1 year ago

@DzmitryHumianiuk yes, we can ask Karate team to do this enhancement for future agent improvements. As for the workaround - it will be the only way for this agent to keep the proper steps order in ReportPortal, unless there also be added an improvement in ReportPortal to track the steps not only by startTime.

DzmitryHumianiuk commented 1 year ago

@vrymar, let's keep this workaround in place for now. The Karate team will also assist us with the other levels.

As a long-term goal, we will consider making improvements on the backend side. However, this is a significant task and won't be implemented in the coming months; it will take some time.

We plan to introduce microsecond precision in RPv6, but this still won't solve the sequence processing issue for async calls. To address this, the RP backend needs to receive the order field in addition to the start time. This could be either a time difference or a combination of startTime and order if the time is the same, down to the millisecond or microsecond. This approach would then work as a secondary parameter for sorting logs when making requests to the database.

@vrymar Peter from Karate team will add index for the same time objects: https://github.com/karatelabs/karate/issues/2383#issuecomment-1697615378 karate already has it internally, just missing in the JSON response.

DzmitryHumianiuk commented 1 year ago

@vrymar overall, considering that our workaround is in place, it seems like we are ready to merge all of this. Is that correct?

@HardNorth ?

vrymar commented 1 year ago

@DzmitryHumianiuk I'm going to make some improvements related to the latest Karate version compatibility. Also @HardNorth please assist with build.gradle file. There is version inconsistency with the referenced *.gradle files: https://github.com/reportportal/agent-java-karate/pull/17#issuecomment-1653157158

vrymar commented 1 year ago

@DzmitryHumianiuk @HardNorth refactoring is done.

vrymar commented 1 year ago

1 more issue is found (thanks to Oleksii Rykhliuk QA Automation Engineer): https://github.com/vrymar/agent-java-karate/issues/38 Parallel runs don't work. Looks like an issue is related to this piece of code in Karate: https://github.com/karatelabs/karate/blob/8e023e4e214b1cb889fea06415dfa5a5b437ce06/karate-core/src/main/java/com/intuit/karate/Runner.java#L430 Will investigate and update

DzmitryHumianiuk commented 1 year ago

@vrymar 🔥

Pattekkatt commented 1 year ago

Now, it sends all report requests only after finishing all tests and it can be really hard for RP to deal with this amount of requests. I have errors even with only ~160 scenarios in the results

11:22:24   08:22:24.836 [main] ERROR com.epam.reportportal.service.Launch - Unable to finish launch in ReportPortal
11:22:24   java.util.concurrent.TimeoutException: The source did not signal an event for 300 seconds and has been terminated.
11:22:24     at io.reactivex.internal.operators.completable.CompletableTimeout$DisposeTask.run(CompletableTimeout.java:109)
11:22:24     at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:38)
11:22:24     at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:26)
11:22:24     at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
11:22:24     at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
11:22:24     at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
11:22:24     at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
11:22:24     at java.base/java.lang.Thread.run(Thread.java:833)
DzmitryHumianiuk commented 1 year ago

@Pattekkatt what is the volume of your test execution? How many test cases were in it?

Pattekkatt commented 1 year ago

@DzmitryHumianiuk 40 features with total of 170 scenarios in it

vrymar commented 12 months ago

@DzmitryHumianiuk is it RP performance issue? Or should we look for another solution within the agent? FYI: here we have 27 features with ~189 scenarios and it works fine. ReportPortal is installed in Azure Cloud.

DzmitryHumianiuk commented 12 months ago

@vrymar, ReportPortal can definitely handle the load you're mentioning, as well as the example from @Pattekkatt. @Pattekkatt, for you, it might be an issue with the ReportPortal instance configuration.

Generally speaking, Karate presents some challenges for ReportPortal due to how it generates events and manages execution. Given that Karate can also perform performance testing, it might produce peak loads when initiating multiple objects.

Ideally, on the ReportPortal side, we should develop a method to handle batched creation requests. Similarly, Karate should be set up to send batched requests. This approach would best address Karate's performance style.