allure-java icon indicating copy to clipboard operation
allure-java copied to clipboard

[allure-restassured] Could't render http attachment file

Open tolbala opened this issue 2 years ago • 14 comments

Describe the bug The response couldn't be attached to the allure report.

io.qameta.allure.attachment.AttachmentRenderException: Could't render http attachment file at io.qameta.allure.attachment.FreemarkerAttachmentRenderer.render(FreemarkerAttachmentRenderer.java:49) at io.qameta.allure.attachment.FreemarkerAttachmentRenderer.render(FreemarkerAttachmentRenderer.java:28) at io.qameta.allure.attachment.DefaultAttachmentProcessor.addAttachment(DefaultAttachmentProcessor.java:41) at io.qameta.allure.restassured.AllureRestAssured.filter(AllureRestAssured.java:119) at io.restassured.filter.Filter$filter.call(Unknown Source) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:46) at io.restassured.filter.Filter$filter.call(Unknown Source) at io.restassured.internal.filter.FilterContextImpl.next(FilterContextImpl.groovy:72) at io.restassured.filter.log.StatusCodeBasedLoggingFilter.filter(StatusCodeBasedLoggingFilter.java:112) at io.restassured.filter.log.ResponseLoggingFilter.filter(ResponseLoggingFilter.java:31) at io.restassured.filter.Filter$filter.call(Unknown Source) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:46) at io.restassured.filter.Filter$filter.call(Unknown Source) at io.restassured.internal.filter.FilterContextImpl.next(FilterContextImpl.groovy:72) at io.restassured.filter.log.RequestLoggingFilter.filter(RequestLoggingFilter.java:146) at io.restassured.filter.Filter$filter.call(Unknown Source) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:46) at io.restassured.filter.Filter$filter.call(Unknown Source) at io.restassured.internal.filter.FilterContextImpl.next(FilterContextImpl.groovy:72) at ........Filters.lambda$requestAndResponseFilter$0(Filters.java:19) at io.restassured.filter.Filter$filter.call(Unknown Source) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:46) at io.restassured.filter.Filter$filter$0.call(Unknown Source) at io.restassured.internal.filter.FilterContextImpl.next(FilterContextImpl.groovy:72) at io.restassured.filter.FilterContext$next.call(Unknown Source) at io.restassured.internal.RequestSpecificationImpl.applyPathParamsAndSendRequest(RequestSpecificationImpl.groovy:1686) at io.restassured.internal.RequestSpecificationImpl.this$2$applyPathParamsAndSendRequest(RequestSpecificationImpl.groovy) at jdk.internal.reflect.GeneratedMethodAccessor124.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:343) at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:328) at groovy.lang.MetaClassImpl.doInvokeMethod(MetaClassImpl.java:1369) at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1103) at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1009) at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:792) at io.restassured.internal.RequestSpecificationImpl.invokeMethod(RequestSpecificationImpl.groovy) at org.codehaus.groovy.runtime.callsite.PogoInterceptableSite.call(PogoInterceptableSite.java:46) at org.codehaus.groovy.runtime.callsite.PogoInterceptableSite.callCurrent(PogoInterceptableSite.java:57) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:203) at io.restassured.internal.RequestSpecificationImpl.applyPathParamsAndSendRequest(RequestSpecificationImpl.groovy:1692) at io.restassured.internal.RequestSpecificationImpl.this$2$applyPathParamsAndSendRequest(RequestSpecificationImpl.groovy) at jdk.internal.reflect.GeneratedMethodAccessor123.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:343) at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:328) at groovy.lang.MetaClassImpl.doInvokeMethod(MetaClassImpl.java:1369) at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1103) at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1009) at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:792) at io.restassured.internal.RequestSpecificationImpl.invokeMethod(RequestSpecificationImpl.groovy) at org.codehaus.groovy.runtime.callsite.PogoInterceptableSite.call(PogoInterceptableSite.java:46) at org.codehaus.groovy.runtime.callsite.PogoInterceptableSite.callCurrent(PogoInterceptableSite.java:57) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:203) at io.restassured.internal.RequestSpecificationImpl.get(RequestSpecificationImpl.groovy:176) at io.restassured.internal.RequestSpecificationImpl.get(RequestSpecificationImpl.groovy) ....... at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:725) at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) at io.qameta.allure.junit5.AllureJunit5.interceptTestTemplateMethod(AllureJunit5.java:59) at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115) at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149) at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140) at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestTemplateMethod(TimeoutExtension.java:92) at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115) at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104) at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:214) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:210) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:135) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:66) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138) at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95) at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185) at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService.submit(ForkJoinPoolHierarchicalTestExecutorService.java:118) at org.junit.platform.engine.support.hierarchical.NodeTestTask$DefaultDynamicTestExecutor.execute(NodeTestTask.java:226) at org.junit.platform.engine.support.hierarchical.NodeTestTask$DefaultDynamicTestExecutor.execute(NodeTestTask.java:204) at org.junit.jupiter.engine.descriptor.TestTemplateTestDescriptor.execute(TestTemplateTestDescriptor.java:139) at org.junit.jupiter.engine.descriptor.TestTemplateTestDescriptor.lambda$execute$2(TestTemplateTestDescriptor.java:107) at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:276) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:276) at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) at org.junit.jupiter.engine.descriptor.TestTemplateTestDescriptor.execute(TestTemplateTestDescriptor.java:107) at org.junit.jupiter.engine.descriptor.TestTemplateTestDescriptor.execute(TestTemplateTestDescriptor.java:42) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138) at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95) at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185) at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:194) at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) at java.base/java.util.concurrent.ForkJoinTask.awaitDone(ForkJoinTask.java:436) at java.base/java.util.concurrent.ForkJoinTask.join(ForkJoinTask.java:670) at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService.joinConcurrentTasksInReverseOrderToEnableWorkStealing(ForkJoinPoolHierarchicalTestExecutorService.java:162) at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService.invokeAll(ForkJoinPoolHierarchicalTestExecutorService.java:136) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141) at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138) at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95) at org.junit.platform.engine.support.hierarchical.ForkJoinPoolHierarchicalTestExecutorService$ExclusiveTask.compute(ForkJoinPoolHierarchicalTestExecutorService.java:185) at java.base/java.util.concurrent.RecursiveAction.exec(RecursiveAction.java:194) at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182) at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655) at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622) at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) Caused by: java.lang.IndexOutOfBoundsException: start 333, end 0, length 2218 at java.base/java.lang.AbstractStringBuilder.checkRange(AbstractStringBuilder.java:1802) at java.base/java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:680) at java.base/java.lang.StringBuffer.append(StringBuffer.java:388) at java.base/java.io.StringWriter.write(StringWriter.java:122) at freemarker.template.utility.StringUtil.XMLOrHTMLEnc(StringUtil.java:215) at freemarker.template.utility.StringUtil.XHTMLEnc(StringUtil.java:105) at freemarker.core.HTMLOutputFormat.output(HTMLOutputFormat.java:62) at freemarker.core.DollarVariable.accept(DollarVariable.java:68) at freemarker.core.Environment.visit(Environment.java:347) at freemarker.core.Environment.visit(Environment.java:353) at freemarker.core.Environment.visit(Environment.java:353) at freemarker.core.Environment.process(Environment.java:326) at freemarker.template.Template.process(Template.java:383) at io.qameta.allure.attachment.FreemarkerAttachmentRenderer.render(FreemarkerAttachmentRenderer.java:46) ... 169 more

Expected behaviour The response is successfully attached to the allure report or the filter is ignored by RestAssured if it throws an exception.

Versions Java version: openjdk 17.0.2 Maven: 3.8.4

allure-junit5:2.17.3 rest-assured:4.3.3 allure-rest-assured:2.17.3 junit-jupiter-params:5.7.0 allure-maven:2.11.2 aspectjweaver:1.9.8

Additional info Tests are executed in parallel. The issue cannot be reproduced constantly. The issue occurred when the size of the response was large.

tolbala avatar Jun 17 '22 19:06 tolbala

It is randomly happing also to us and it is really annoying. Sometimes it fails , sometimes it passes with the same response body. I spend a lot of time digging in the code but I was not able to identify if it is issue on Allure side or Freemarker side or somewhere else.

For example for us it is very often failing with the following response body

{
    "message": "Token claims invalid: [\"exp\"]=\"token expired\""
}

with exception:

....
Caused by: java.lang.IndexOutOfBoundsException: start 67, end 0, length 70
	at java.base/java.lang.AbstractStringBuilder.checkRange(AbstractStringBuilder.java:1802)
	at java.base/java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:680)
	at java.base/java.lang.StringBuffer.append(StringBuffer.java:393)
	at java.base/java.io.StringWriter.write(StringWriter.java:122)
	at freemarker.template.utility.StringUtil.XMLOrHTMLEnc(StringUtil.java:215)
	at freemarker.template.utility.StringUtil.XHTMLEnc(StringUtil.java:105)
	at freemarker.core.HTMLOutputFormat.output(HTMLOutputFormat.java:62)
	at freemarker.core.DollarVariable.accept(DollarVariable.java:68)
	at freemarker.core.Environment.visit(Environment.java:347)
	at freemarker.core.Environment.visit(Environment.java:353)
	at freemarker.core.Environment.visit(Environment.java:353)
	at freemarker.core.Environment.process(Environment.java:326)
	at freemarker.template.Template.process(Template.java:383)
	at io.qameta.allure.attachment.FreemarkerAttachmentRenderer.render(FreemarkerAttachmentRenderer.java:46)

And if start = 67 and end = 0 in java.base/java.lang.AbstractStringBuilder.checkRange then on line 215 in freemarker.template.utility.StringUtil.XMLOrHTMLEnc method writtenEnd must be 67 and flushLn must -67 and based on the algorithm in freemarker.template.utility.StringUtil.XMLOrHTMLEnc method I guess it cannot happen. So it is weird.

We are not running tests in parallel. It is quite often happening with this specific response I provided hereinbefore. Rarely with larger responses.

We are using: Allure 2.18.1 => Freemarker 2.3.31 Junit 5.8.2

martinsefcik avatar Aug 09 '22 10:08 martinsefcik

@martinsefcik I've implemented a workaround that basically just catches the exception and adds some logs to the report. The implementation is almost the same as it is in the allure-restassured lib, but the execution won't fail due to the rendering exception.

public static Filter safeAllureRestAssured() {

        return (reqSpec, respSpec, ctx) -> {
            final Response response = ctx.next(reqSpec, respSpec);
            final Prettifier prettifier = new Prettifier();
            final String url = reqSpec.getURI();

            final HttpRequestAttachment.Builder requestAttachmentBuilder = create("Request", url)
                .setMethod(reqSpec.getMethod())
                .setHeaders(toMapConverter(reqSpec.getHeaders()))
                .setCookies(toMapConverter(reqSpec.getCookies()));

            if (Objects.nonNull(reqSpec.getBody())) {
                requestAttachmentBuilder.setBody(prettifier.getPrettifiedBodyIfPossible(reqSpec));
            }

            final HttpRequestAttachment requestAttachment = requestAttachmentBuilder.build();
            try {
                new DefaultAttachmentProcessor().addAttachment(
                    requestAttachment,
                    new FreemarkerAttachmentRenderer("http-request.ftl")
                );
            } catch (AttachmentRenderException ignore) {
                log.error("AttachmentRenderException occurred during attaching the request to the report.");
                attachLogs("Request", getRequestLog(requestAttachment));
            }

            String responseAttachmentName = response.getStatusLine();

            final HttpResponseAttachment responseAttachment = HttpResponseAttachment.Builder.create(
                responseAttachmentName
            )
                .setResponseCode(response.getStatusCode())
                .setHeaders(toMapConverter(response.getHeaders()))
                .setBody(prettifier.getPrettifiedBodyIfPossible(response, response.getBody()))
                .build();

            try {
                new DefaultAttachmentProcessor().addAttachment(
                    responseAttachment,
                    new FreemarkerAttachmentRenderer("http-response.ftl")
                );
            } catch (AttachmentRenderException e) {
                log.error("AttachmentRenderException occurred during attaching the Response to the report.");
                attachLogs("Response", getResponseLog(responseAttachment));
            }

            return response;
        };
    }

Usage: RestAssured.replaceFiltersWith(Filters.safeAllureRestAssured());

tolbala avatar Aug 09 '22 12:08 tolbala

@tolbala Thank you for workaround. Could you also provide implementation for attachLogs(), getRequestLog() and getResponseLog() methods ?

martinsefcik avatar Aug 09 '22 13:08 martinsefcik

@martinsefcik Here you can find the implementation of the missing methods:

private static String getRequestLog(HttpRequestAttachment requestAttachment) {
       return """
               Method: %s
               URL: %s
               Body: %s
               """.formatted(
           requestAttachment.getMethod(),
           requestAttachment.getUrl(),
           requestAttachment.getBody()
       );
   }

   private static String getResponseLog(HttpResponseAttachment responseAttachment) {
       return """
               Status Code: %s
               Body: %s
               """.formatted(
           responseAttachment.getResponseCode(),
           responseAttachment.getBody()
       );
   }

   private static void attachLogs(String name, String content) {
       Allure.getLifecycle()
           .addAttachment(
               name,
               "text/plain",
               "txt",
               content.getBytes(StandardCharsets.UTF_8)
           );
   }

I've spent a couple of hours debugging the code, trying different combinations of the lib versions(allure, restassured, allure-restassured, etc.), but I was unable to reproduce the issue constantly so I don't know what causes the issue.

tolbala avatar Aug 09 '22 16:08 tolbala

We've started encountering this issue last week too and are pretty stumped on what could be causing it. From our troubleshooting so far we've determined

  • Issue seems to be related to empty string "" in request body in our case
  • If we switch this to " ", the problem goes away. But in some cases this changes the actual test, so is not always possible
  • If we only run some of the tests, the problem doesn't occur
  • But if we run all tests, the issue can be reproduced consistently (so far at least)
  • If we run the tests in the IDE (IntelliJ IDEA) in debug mode, the issue doesn't occur (making it nearly impossible to debug)
  • If we run against OpenJDK17 we don't see the issue (from our limited testing)
  • If we run against libericaJDK 17 or Eclipse Temurin JDK 17 we see the issue
  • Switching to OpenJDK isn't an option however as we're running out tests on Azure DevOps pipeline which only includes Temurin JDK
  • Like everybody else above, we're seeing IndexOutOfBoundsException where the end value is zero
  • Checked the output of mvn dependency:tree and confirmed that nothing else is pulling in another version of freemarker
  • Updating to latest version of Freemarker doesn't resolve the issue

I've tried creating a test project which sends an identical request to https://reqres.in over and over again, and yet I can't reproduce the issue there. No idea why, And a search on the freemarker github repo for IndexOutOfBoundsException reveals zero results :-(

Versions

  • TestNG 7.6.1
  • rest-assured 5.2.0
  • Allure (including allure rest assured) 2.20

mmcdermo2 avatar Nov 29 '22 10:11 mmcdermo2

@mmcdermo2 for us it was also failing on libericaJDK 17

martinsefcik avatar Nov 29 '22 13:11 martinsefcik

We have such problem too.

Java Liberica 17 Cucumber 7 rest-assured 5.2.0 allure-rest-assured 2.19.0

NewbieProger avatar Nov 30 '22 10:11 NewbieProger

Got this error too.

Java 17 rest-assured 5.3.1 allure-rest-assured 2.23.0 alure-gradle-plugin 2.11.2 (no Cucumber)

pavelicii avatar Sep 07 '23 18:09 pavelicii

@pavelicii Which JDK distribution? Liberica?

martinsefcik avatar Sep 07 '23 18:09 martinsefcik

@martinsefcik Oracle JDK.

pavelicii avatar Sep 07 '23 18:09 pavelicii

We have got the same error too. Java 17.0.8 Gradle 7.3 Junit 5.8.2 Rest assured 4.5.0 Allure 2.20.0 Allure Gradle plugin 2.11.0

This error happens only if we run tests in CI (image based on linux (alpine) with java and gradle), for local runs everything is ok. We use junit multitheaded run:

"junit.jupiter.extensions.autodetection.enabled": true,
"junit.jupiter.execution.parallel.enabled": true,
"junit.jupiter.execution.parallel.mode.default": "same_thread",
"junit.jupiter.execution.parallel.mode.classes.default": "concurrent"

wavesrcomn avatar Sep 11 '23 12:09 wavesrcomn

@martinsefcik Have you been able to re-create the problem in any reproducible way on local machine, on host or docker container? I've observed exactly same problem, on AWS ECS container running ubuntu 20.04 with eclipse temurin 17.0.3_7-jre. We do not use allure, we use freemarker to generate some html based on a template. Top of the stack trace is however the same, call to freemarker.template.utility.StringUtil.XMLOrHTMLEnc(StringUtil.java:215) ends with IndexOutOfBoundsException where end is 0, and start > 0.

I also spent some time analyzing codes and I have same observarions like you: So considering https://github.com/apache/freemarker/blob/v2.3.31/src/main/java/freemarker/template/utility/StringUtil.java#L215 and java.lang.IndexOutOfBoundsException: start 67, end 0, length 70

  • if start is 67, then writtenEnd has to be 67.
  • end is calculated as start + flushLn (https://github.com/openjdk/jdk17/blob/4afbcaf55383ec2f5da53282a1547bac3d099e9d/src/java.base/share/classes/java/io/StringWriter.java#L122) , so if end is 0, then flushLn has to be -writtenEnd.
  • int flushLn = i - writtenEnd;, so i has to be 0.
  • but if i == 0 we are in first iteration of the loop, so writtenEnd should also be 0, but this contradicts the first point.

i, writtenEnd, flushLn are local variables and there are no other threads spawn inside the method. This also applies to StringBuilder etc. This makes me thinking it could be JIT or instrumentation related. However it is hard to confirm that, as it happened only once. Do you use some unusual JVM flags, java agents or instrumentation methods? Does it happened only in cloud? Does the exception is always thrown from this line: https://github.com/apache/freemarker/blob/v2.3.31/src/main/java/freemarker/template/utility/StringUtil.java#L215 and never from this one: https://github.com/apache/freemarker/blob/v2.3.31/src/main/java/freemarker/template/utility/StringUtil.java#L229 ? What exactly java 17 version do you use? (build)

sokolek avatar Oct 07 '23 08:10 sokolek

Upgrading Java version fixed this issue for me. Flaky version was with maven:3.8-openjdk-17 Docker image, Java version: 17.0.2, vendor: Oracle Corporation Upgrade to maven:3.9-eclipse-temurin-17 Docker image, Java version: 17.0.8.1, vendor: Eclipse Adoptium

Sample request body with empty quotation marks "":

{
    "status": 200,
    "headers": {
        "Content-Type": "application/json"
    },
    "responseBody": ""
}

Sample error, always on StringUtil.java line 215:

Caused by: java.lang.IndexOutOfBoundsException: start 109, end 0, length 112
	at java.base/java.lang.AbstractStringBuilder.checkRange(AbstractStringBuilder.java:1802)
	at java.base/java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:680)
	at java.base/java.lang.StringBuffer.append(StringBuffer.java:393)
	at java.base/java.io.StringWriter.write(StringWriter.java:122)
	at freemarker.template.utility.StringUtil.XMLOrHTMLEnc(StringUtil.java:215)
	at freemarker.template.utility.StringUtil.XHTMLEnc(StringUtil.java:105)

RasmusSoot avatar Oct 18 '23 08:10 RasmusSoot