Endava / cats

CATS is a REST API Fuzzer and negative testing tool for OpenAPI endpoints. CATS automatically generates, runs and reports tests with minimum configuration and no coding effort. Tests are self-healing and do not require maintenance.
Apache License 2.0
1.11k stars 75 forks source link

Getting ResponseCode 999 and log shows Fuzzer [VeryLargeUnicodeValuesInFieldsFuzzer] failed due to [java.net.ProtocolException: Unexpected status line: #40

Closed stuti100 closed 1 year ago

stuti100 commented 2 years ago

I was running CATS with 1 Api and got this error response code shows 999.What does that mean?Log shows :
Exception while processing!: com.endava.cats.io.CatsIOException: java.net.ProtocolException: Unexpected status line: 62\uDCD4?\uD848\uDC6F????\uD855]...[\uDD52?\uD84A\uDE5E?\uD801\uDE64\uD808\uDEDC\uD87E\uDD85\uD81A\uDF26??\uD85D\uDF9C?\uD81F\uDC4F\uD804\uDEB5\uD865\uDF0A??\uD854\uDFC7???\uD86E\uDE22\uD84D\uDC51\uD840\uDF2B\uD862\uDC16??\uD86D\uDF89\uD835\uDFC8??\uD804\uDDAB?????\uD844\uDCEE\uD844\uDC83???\uD85C\uDDA7\uD842\uDF9B??\uD855\uDDCC?\\uD850\uDFAA\uD85B\uDE6F??\uD864\uDCF7?????\uD82C\uDE49\uD876\uDEF7\uD811\uDD6B\uD808\uDD16?\uD850\uDD65\uD800\uDF51????\uD81F\uDC62?????\uD86F\uDC16\uD872\uDEFF\uD83D\uDD85?\uD85A\uDF50\uD863\uDF05\uD85C\uDCBF\uD857\uDEF8?\uD842\uDCBE?\uD85C\uDFF7\uD86A\uDEB5??\uD848\uDFB8ts\": only \"true\" or \"false\" recognized\n at [Source: (ByteArrayInputStream); line: 1, column: 636] (through reference chain: Animal[\"land\"]->AnimalLand[\"reptiles\"]->AnimalReptiles[\"lizard\"])"}HTTP/1.1 400 Bad Request at com.endava.cats.io.ServiceCaller.call(ServiceCaller.java:214) at com.endava.cats.io.ServiceCaller_Subclass.call$$superforward1(Unknown Source) at com.endava.cats.io.ServiceCaller_Subclass$$function$$1.apply(Unknown Source) at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54) at com.endava.cats.aop.DryRunAspect.intercept(DryRunAspect.java:95) at com.endava.cats.aop.DryRunAspect_Bean.intercept(Unknown Source) at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41) at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41) at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32) at com.endava.cats.io.ServiceCaller_Subclass.call(Unknown Source) at com.endava.cats.io.ServiceCaller_ClientProxy.call(Unknown Source) at com.endava.cats.fuzzer.fields.base.BaseFieldsFuzzer.process(BaseFieldsFuzzer.java:86) at com.endava.cats.fuzzer.fields.base.BaseFieldsFuzzer.lambda$fuzz$0(BaseFieldsFuzzer.java:65) at com.endava.cats.report.TestCaseListener.createAndExecuteTest(TestCaseListener.java:109) at com.endava.cats.report.TestCaseListener_Subclass.createAndExecuteTest$$superforward1(Unknown Source) at com.endava.cats.report.TestCaseListener_Subclass$$function$$27.apply(Unknown Source) at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54) at com.endava.cats.aop.DryRunAspect.intercept(DryRunAspect.java:95) at com.endava.cats.aop.DryRunAspect_Bean.intercept(Unknown Source) at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41) at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41) at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32) at com.endava.cats.report.TestCaseListener_Subclass.createAndExecuteTest(Unknown Source) at com.endava.cats.report.TestCaseListener_ClientProxy.createAndExecuteTest(Unknown Source) at com.endava.cats.fuzzer.fields.base.BaseFieldsFuzzer.fuzz(BaseFieldsFuzzer.java:65) at com.endava.cats.command.CatsCommand.lambda$fuzzPath$6(CatsCommand.java:227) at java.base/java.util.ArrayList.forEach(ArrayList.java:1541) at com.endava.cats.command.CatsCommand.fuzzPath(CatsCommand.java:224) at com.endava.cats.command.CatsCommand.startFuzzing(CatsCommand.java:137) at com.endava.cats.command.CatsCommand.doLogic(CatsCommand.java:121) at com.endava.cats.command.CatsCommand.run(CatsCommand.java:108) at picocli.CommandLine.executeUserObject(CommandLine.java:1939) at picocli.CommandLine.access$1300(CommandLine.java:145) at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2358) at picocli.CommandLine$RunLast.handle(CommandLine.java:2352) at picocli.CommandLine$RunLast.handle(CommandLine.java:2314) at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2179) at picocli.CommandLine$RunLast.execute(CommandLine.java:2316) at picocli.CommandLine.execute(CommandLine.java:2078) at com.endava.cats.CatsMain.run(CatsMain.java:27) at com.endava.cats.CatsMain_ClientProxy.run(Unknown Source) at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:124) at io.quarkus.runtime.Quarkus.run(Quarkus.java:67) at io.quarkus.runtime.Quarkus.run(Quarkus.java:41) at io.quarkus.runner.GeneratedMain.main(Unknown Source) Caused by: java.net.ProtocolException: Unexpected status line: 62\uDCD4?\uD848\uDC6F????\uD855]...[\uDD52?\uD84A\uDE5E?\uD801\uDE64\uD808\uDEDC\uD87E\uDD85\uD81A\uDF26??\uD85D\uDF9C?\uD81F\uDC4F\uD804\uDEB5\uD865\uDF0A??\uD854\uDFC7???\uD86F\uDC16\uD872\uDEFF\uD83D\uDD85?\uD85A\uDF50\uD863\uDF05\uD85C\uDCBF\uD857\uDEF8?\uD842\uDCBE?\uD85C\uDFF7\uD86A\uDEB5??\uD848\uDFB8ts\": only \"true\" or \"false\" recognized\n at [Source: (ByteArrayInputStream); line: 1, column: 636] (through reference chain: Animal[\"land\"]->AnimalLand[\"reptiles\"]->AnimalReptiles[\"lizard\"])"}HTTP/1.1 400 Bad Request at okhttp3.internal.http.StatusLine$Companion.parse(StatusLine.kt:80) at okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:178) at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:106) at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:79) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201) at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154) at com.endava.cats.io.ServiceCaller.callService(ServiceCaller.java:349) at com.endava.cats.io.ServiceCaller.call(ServiceCaller.java:208) ... 44 more Please provide some info on it and how to resolve this.Open Api spec attached

en-milie commented 2 years ago

Hi @stuti100. As the error is reported by the http library it's seems more related to how the service responds vs a problem with the OpenAPI spec. Are you able to properly send and receive requests/responses using other tools (curl, Postman, etc)? If yes, maybe this exact payload causes your service to crash and fail to properly respond. Try to do a manual call with the same payload and see what happens.

stuti100 commented 2 years ago

Hi @en-milie ,Thanks for the follow-up. For some requests Postman shows 400 Bad request error,But the CATS reports are showing 999, Even though if we see the logs and reports generated by CATS they too are considering it as 400 Bad request(As mentioned in above code block) but recording it as 999 error response code.

Screenshot 2022-04-22 at 5 47 37 PM image
en-milie commented 2 years ago

I suspect this is a bug in the http library I'm using which is okhttp. the server responds with a series of characters preceding the 400 HTTP 1.1 which okhttp cannot properly parse. is there a public api endpoint I can do some testing with? I suspect not, but worth asking.

en-milie commented 2 years ago

Hi @stuti100. Is there any chance to get access to an API endpoint? Also, the OpenAPI spec is not attached in the first comment.

en-milie commented 2 years ago

I'll close this for now. In case this is not fixed, please re-open it with more deails.

rhtenhove commented 1 year ago

@en-milie I'm experiencing this as well with an internal project. I wish to deploy this using CI, so I've created a project which does testing on a demo server from RESTler.

The results show 3 errors, all of which are from the VeryLargeUnicodeValuesInHeadersFuzzer (example).

I'm seeing dozens of 999s with the internal project, also with NonRestHttpMethodsFuzzer: Fuzzer [NonRestHttpMethodsFuzzer] failed due to [java.io.IOException: unexpected end of stream on http://target:3000/...]. Can't share that endpoint though.

Getting the RESTler demo running is easy as:

docker run --rm -p 8888:8888 registry.gitlab.com/just-ci/tools/security/cats-runner/demo_server:latest

Spec is here

en-milie commented 1 year ago

Thanks for raising it. I'll take a look and get back.

en-milie commented 1 year ago

Hi @rhtenhove. I'm trying to reproduce the issue, but I get valid request/responses in the report. For the VeryLargeUnicodeValuesInHeadersFuzzer I get 431 returned by the RESTler demo app. As for the "java.io.IOException: unexpected end of stream on" this usually signals a service side issue. During exceptional situations the server fails to add proper headers to the response and the client (CATS in this case) will not know how to parse the response as it reuses connections.

In the next release I'll improve reporting a bit for the error cases.

en-milie commented 1 year ago

@rhtenhove Can you please try the following build and let me know if you still get the 999s and the end of streams. https://drive.google.com/file/d/1e4Hk7F18q-1sg5aK_mV7dm2BIkQsNc3T/view?usp=sharing

rhtenhove commented 1 year ago

Thanks for the response!

There appears to be a difference between using Shared Runners and self hosted Runners on GitLab, where the former causes java.net.SocketException: Broken pipe. The latter succesfully runs all fuzzers against the target on the RESTler demo.

The internal project still produces plenty of errors varying between Connection reset and end of stream. Even with the 7.3.3 version.

curl produces curl: (52) Empty reply from server when reproducing one of the errors, which makes sense.

The report properly categorizes them as Unexpected Exception, which is fine. Perhaps these can be parsed by CATS, as curl does, as 'empty reply' as well?

I guess the remaining problem is the large stack traces bloating the console log and showing information not relevant to the test. Is there a way to disable those?

en-milie commented 1 year ago

Thanks for the suggestion. I'll wrap common types of connection exceptions into something more readable.

As for the verbosity, you can use the --log argument. --log "com.endava.cats:off" will switch off all logging. --log "com.endava.cats:error" will only print errors.

en-milie commented 1 year ago

@rhtenhove is anything else not working? Starting with version 8 of CATS you can also use --log "off" to switch off all logging.

rhtenhove commented 1 year ago

@en-milie Thanks for the suggestions. The problem remains that the choice is either have no logging at all, or have the (in case of the target not behaving well) logs filled of large error messages as the level of the stack traces is 'error' which is quite high, and is a level I'd like to definitely see logging of as it may help show problems that otherwise would go unnoticed.

Example with v8.0.0: https://gitlab.com/just-ci/tools/security/cats-runner/-/jobs/3029466601

Did you manage to add the feature of wrapping connection exceptions in v8 ?

en-milie commented 1 year ago

@rhtenhove connection exceptions are now wrapped as "empty content". I'll do a review of all logging and most likely will switch stack traces to debug, as they are not that useful for the end user, but rather for fixing bugs.

en-milie commented 1 year ago

Logging is less verbose by default in: https://github.com/Endava/cats/releases/tag/cats-8.1.0

rhtenhove commented 1 year ago

Gave it a try, very nice!

I'd say this issue can be closed.

en-milie commented 1 year ago

Ok. I'll close this one. The next release will include even more granular control.