Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jakarta - EE 10 - AWT test failures #27809

Closed
gsmet opened this issue Sep 8, 2022 · 26 comments · Fixed by #28261
Closed

Jakarta - EE 10 - AWT test failures #27809

gsmet opened this issue Sep 8, 2022 · 26 comments · Fixed by #28261

Comments

@gsmet
Copy link
Member

gsmet commented Sep 8, 2022

Since the upgrade to RESTEasy 6.1, AWT tests for ImageDecodersTest#testComplexImages are failing in the jakarta-rewrite branch (for more information, see https://github.com/quarkusio/quarkus/tree/main/jakarta#build-locally):

Typically in integration-tests/awt which makes use of multipart to upload images (in JVM mode):

[INFO] Results:
[INFO] 
[ERROR] Errors: 
[ERROR]   ImageDecodersTest.testComplexImages:171 » ConditionTimeout Assertion condition defined as a lambda expression in io.quarkus.awt.it.TestUtil that uses java.nio.file.Path, java.nio.file.Pathjava.util.regex.Pattern, java.util.regex.Patternjava.lang.String test_jpeg.tiff: Log file doesn't contain a line matching (?i:.*(type = 6 .* #pixelBits = 32 numComponents = 4 |test_jpeg.tiff.*Unsupported Image Type).*), log was: 14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard BMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard GIF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard TIFF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard PNG image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard WBMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard JPEG Image Reader
14:13:20 INFO  [io.quarkus] (main) quarkus-integration-test-awt 999-jakarta-SNAPSHOT on JVM (powered by Quarkus 999-jakarta-SNAPSHOT) started in 1.451s. Listening on: http://localhost:8081
14:13:20 INFO  [io.quarkus] (main) Profile test activated. 
14:13:20 INFO  [io.quarkus] (main) Installed features: [awt, cdi, resteasy, resteasy-multipart, smallrye-context-propagation, vertx]
 ==> expected: <true> but was: <false> within 3 seconds.
[ERROR]   ImageDecodersTest.testComplexImages:165 » ConditionTimeout Assertion condition defined as a lambda expression in io.quarkus.awt.it.TestUtil that uses java.nio.file.Path, java.nio.file.Pathjava.util.regex.Pattern, java.util.regex.Patternjava.lang.String test_jpeg_2.tiff: Log file doesn't contain a line matching .*test_jpeg_2.tiff.*Unsupported Image Type.*, log was: 14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard BMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard GIF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard TIFF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard PNG image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard WBMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard JPEG Image Reader
14:13:20 INFO  [io.quarkus] (main) quarkus-integration-test-awt 999-jakarta-SNAPSHOT on JVM (powered by Quarkus 999-jakarta-SNAPSHOT) started in 1.451s. Listening on: http://localhost:8081
14:13:20 INFO  [io.quarkus] (main) Profile test activated. 
14:13:20 INFO  [io.quarkus] (main) Installed features: [awt, cdi, resteasy, resteasy-multipart, smallrye-context-propagation, vertx]
 ==> expected: <true> but was: <false> within 3 seconds.
[ERROR]   ImageDecodersTest.testComplexImages:165 » ConditionTimeout Assertion condition defined as a lambda expression in io.quarkus.awt.it.TestUtil that uses java.nio.file.Path, java.nio.file.Pathjava.util.regex.Pattern, java.util.regex.Patternjava.lang.String weird_230.bmp: Log file doesn't contain a line matching .*weird_230.bmp.*New BMP version not implemented yet.*, log was: 14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard BMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard GIF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard TIFF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard PNG image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard WBMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard JPEG Image Reader
14:13:20 INFO  [io.quarkus] (main) quarkus-integration-test-awt 999-jakarta-SNAPSHOT on JVM (powered by Quarkus 999-jakarta-SNAPSHOT) started in 1.451s. Listening on: http://localhost:8081
14:13:20 INFO  [io.quarkus] (main) Profile test activated. 
14:13:20 INFO  [io.quarkus] (main) Installed features: [awt, cdi, resteasy, resteasy-multipart, smallrye-context-propagation, vertx]
 ==> expected: <true> but was: <false> within 3 seconds.
[ERROR]   ImageDecodersTest.testComplexImages:165 » ConditionTimeout Assertion condition defined as a lambda expression in io.quarkus.awt.it.TestUtil that uses java.nio.file.Path, java.nio.file.Pathjava.util.regex.Pattern, java.util.regex.Patternjava.lang.String weird_1000.jpg: Log file doesn't contain a line matching .*weird_1000.jpg.*Bogus Huffman table definition.*, log was: 14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard BMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard GIF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard TIFF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard PNG image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard WBMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard JPEG Image Reader
14:13:20 INFO  [io.quarkus] (main) quarkus-integration-test-awt 999-jakarta-SNAPSHOT on JVM (powered by Quarkus 999-jakarta-SNAPSHOT) started in 1.451s. Listening on: http://localhost:8081
14:13:20 INFO  [io.quarkus] (main) Profile test activated. 
14:13:20 INFO  [io.quarkus] (main) Installed features: [awt, cdi, resteasy, resteasy-multipart, smallrye-context-propagation, vertx]
 ==> expected: <true> but was: <false> within 3 seconds.
[ERROR]   ImageDecodersTest.testComplexImages:165 » ConditionTimeout Assertion condition defined as a lambda expression in io.quarkus.awt.it.TestUtil that uses java.nio.file.Path, java.nio.file.Pathjava.util.regex.Pattern, java.util.regex.Patternjava.lang.String test_gray_to_k.jpg: Log file doesn't contain a line matching .*test_gray_to_k.jpg.*(Can not access.*profile|LUT is not suitable).*, log was: 14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard BMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard GIF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard TIFF image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard PNG image reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard WBMP Image Reader
14:13:20 INFO  [io.qu.aw.it.Application] (main) Available image reader: Standard JPEG Image Reader
14:13:20 INFO  [io.quarkus] (main) quarkus-integration-test-awt 999-jakarta-SNAPSHOT on JVM (powered by Quarkus 999-jakarta-SNAPSHOT) started in 1.451s. Listening on: http://localhost:8081
14:13:20 INFO  [io.quarkus] (main) Profile test activated. 
14:13:20 INFO  [io.quarkus] (main) Installed features: [awt, cdi, resteasy, resteasy-multipart, smallrye-context-propagation, vertx]
 ==> expected: <true> but was: <false> within 3 seconds.

Also, the tests are failing in integration-tests/no-awt but only in native (maybe they are only run in native?):

io.quarkus.awt.it.GraphicsIT.testGraphics(String)[1]

My guess is that it's related.

My guess is that a behavior has changed in RESTEasy related to multipart but I want us to get more details about what is exactly going on before involving James Perkins.

@quarkus-bot
Copy link

quarkus-bot bot commented Sep 8, 2022

/cc @Karm, @galderz, @zakkak

@gsmet
Copy link
Member Author

gsmet commented Sep 8, 2022

@Karm as mentioned in the description, I suspect a problem in RESTEasy but I think we need more details to understand what exactly is not working and what makes the tests fail.

@Sgitario
Copy link
Contributor

Sgitario commented Sep 9, 2022

This is related to this change: resteasy/resteasy#3044. Basically, it will map all the unhandled exceptions to return 500 and collect all the inner exception messages.

This test relies on the exception messages to be logged and this can be enabled using the logger org.jboss.resteasy.core.providerfactory.DefaultExceptionMapper. Will try this direction.

@Sgitario
Copy link
Contributor

Sgitario commented Sep 9, 2022

When enabling the logging for the DefaultExceptionMapper by adding this build step in ResteasyBuiltinsProcessor:

@BuildStep
    void logging(BuildProducer<LogCategoryBuildItem> log) {
        // Increase log level for default exception mapper: https://github.com/resteasy/resteasy/pull/3044
        log.produce(new LogCategoryBuildItem("org.jboss.resteasy.core.providerfactory.DefaultExceptionMapper", Level.FINE));
    }

And running the test again, we got the exception message now:

2022-09-09 12:28:47,496 DEBUG [org.jbo.res.cor.pro.DefaultExceptionMapper] (executor-thread-0) Processing exception with the default exception mapper.: javax.imageio.IIOException: Bogus Huffman table definition
	at java.desktop/com.sun.imageio.plugins.jpeg.JPEGImageReader.readImage(Native Method)
	at java.desktop/com.sun.imageio.plugins.jpeg.JPEGImageReader.readInternal(JPEGImageReader.java:1335)
	at java.desktop/com.sun.imageio.plugins.jpeg.JPEGImageReader.read(JPEGImageReader.java:1127)
	at java.desktop/javax.imageio.ImageReader.readAll(ImageReader.java:1065)

Still we would need to adjust the test exception because we're losing the path. The exception message before Resteasy 6.1 was:

2022-09-09 12:18:00,530 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-0) HTTP Request to /topng/weird_1000.jpg failed, error id: 1d7571ab-dc34-4739-8fe6-9af60cd3bdd1-1: org.jboss.resteasy.spi.UnhandledException: javax.imageio.IIOException: Bogus Huffman table definition
	at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:105)
	at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:359)
	at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:218)

And I don't think this is the right direction as the exception is not going through our QuarkusErrorHandler handler.

Therefore, these are the options I can think of:

  • Using ObjectSubstitutionBuildItem, substitute the DirectExceptionMapper class and that the static field INSTANCE returns null, so we won't apply the default mapper never. But can we do this?
  • Enable the logging as done in the previous lines. Is acceptable to not go through the QuarkusErrorHandler?
  • Maybe ask Resteasy team to support the ability not to provide a default exception mapper?

Wdyt? @gsmet @Karm

@jamezp
Copy link
Contributor

jamezp commented Sep 20, 2022

The only option I can see here is have a way for RESTEasy to disable the default exception mapper with a configuration property. We have to include the default exception mapper per the spec.

The only other option would be to look at the response rather than the logs.

@jamezp
Copy link
Contributor

jamezp commented Sep 20, 2022

Maybe not ideal, but another option is to have Quarkus register it's own ExceptionMapper. As a test I just added this and it worked:

@Provider
public class QuarkusExceptionMapper implements ExceptionMapper<Throwable> {
    @Override
    public Response toResponse(final Throwable exception) {
        throw exception instanceof RuntimeException ? (RuntimeException) exception : new RuntimeException(exception);
    }
}

@Sgitario
Copy link
Contributor

Maybe not ideal, but another option is to have Quarkus register it's own ExceptionMapper. As a test I just added this and it worked:

@Provider
public class QuarkusExceptionMapper implements ExceptionMapper<Throwable> {
    @Override
    public Response toResponse(final Throwable exception) {
        throw exception instanceof RuntimeException ? (RuntimeException) exception : new RuntimeException(exception);
    }
}

I also tried that and spites it fixes the test, it opens a can of worms in other places (many other tests will fail in resteasy-classic) :(

@gsmet
Copy link
Member Author

gsmet commented Sep 21, 2022

@jamezp what I fail to understand is how we can consider than not logging any errors on the server side is an improvement? I mean, from this version of RESTEasy, users have absolutely no idea what's failing anymore. How do you expect people to be able to fix issues?
I don't think requiring people to enable debug logging is reasonable. So I would somehow expect us to log an error by default (preferably with a better error message than what we get with the current debug message because we also lost any context such as the path), all that if it's not a 400.
I might be missing something about why you decided to remove any logging so please explain the rationale if so.

It looks like a detail but I think it's a serious usability regression.

/cc @geoand

@geoand
Copy link
Contributor

geoand commented Sep 21, 2022

So the issue is that RESTEasy now does not automatically log an exception? What kinds of exceptions are we talking about?

@gsmet
Copy link
Member Author

gsmet commented Sep 21, 2022

Well, from what I can see, any exception causing a 500 is not logged anymore (and I suppose any exception really). At least I don't get any stacktrace in the logs when we have an error in a test.

@geoand
Copy link
Contributor

geoand commented Sep 21, 2022

Okay, that does seem problematic.

In RR we always log exceptions that were not handled by any ExceptionMapper.

@gsmet
Copy link
Member Author

gsmet commented Sep 21, 2022

@geoand yeah so the problem is that now the spec mandates a default ExceptionMapper so... :)

@geoand
Copy link
Contributor

geoand commented Sep 21, 2022

In that case, I would log the error in that exception mapper

@Sgitario
Copy link
Contributor

To be precise, this happens to all unhandled exceptions.

The previous behaviour was that all the unhandled exceptions were not mapped by Resteasy, so we could map it using our Quarkus error handler implementation.

With Resteasy 6.x, all the unhandled exceptions are now mapped using a new Default exception mapper that won't log anything unless users configure the log level debug for this new exception mapper. Also, the Quarkus error handler won't do anything in this scenario any longer.

@gsmet
Copy link
Member Author

gsmet commented Sep 21, 2022

@Sgitario do you remember where is the Quarkus exception mapper implementation?

@Sgitario
Copy link
Contributor

@gsmet
Copy link
Member Author

gsmet commented Sep 21, 2022

@Sgitario @geoand @jamezp so even if not spec compliant, I wonder if the best wouldn't be to have a property to not register the default RESTEasy exception mapper in Quarkus and get back to the previous behavior?

Another option would be to override it and provide a behavior similar to QuarkusErrorHandler in the exception mapper but I'm not sure it's such a good idea as it would change the behavior for people who added their own exception mapper.

I think we were pretty much happy with the existing behavior in Quarkus?

@jamezp even if we do that, I'm still unsure the current behavior of not logging anything in RESTEasy is really something you want for WildFly and EAP.

@geoand
Copy link
Contributor

geoand commented Sep 21, 2022

I think we should override it and get back the previous behavior

@gsmet
Copy link
Member Author

gsmet commented Sep 21, 2022

Well I'm not sure it would be so easy to override it and get back to the previous behavior with a JAX-RS exception mapper. Thus why I was suggesting we shouldn't register the default exception mapper in the first place (and thus get back to the previous behavior).
The QuarkusErrorHandler is doing quite some magic and I'm not sure we want to duplicate it.

@jamezp
Copy link
Contributor

jamezp commented Sep 21, 2022

I'm definitely convinced on the logging errors now :) The only reason I went with debug logging to begin with a concern over being too verbose. However, I realize now that was not a good idea.

I can look at a way to not register a default exception mapper. I feel like that idea came from the MP REST Client, but IMO it makes more sense on a client than in the container.

@jamezp
Copy link
Contributor

jamezp commented Sep 21, 2022

I've filed https://issues.redhat.com/browse/RESTEASY-3225 and will work on that this morning. Will a simple property work fine? Something like dev.resteasy.exception.manager=false.

@gsmet
Copy link
Member Author

gsmet commented Sep 21, 2022

Yes, if we have a system property, we can set it in Quarkus using SystemPropertyBuildItem. @geoand @Sgitario works for you?

@geoand
Copy link
Contributor

geoand commented Sep 21, 2022

Fine with me

@jamezp
Copy link
Contributor

jamezp commented Sep 22, 2022

This resteasy/resteasy#3278 includes the ability to disable the default exception mapper. It also does allow the Quarkus test to pass with no changes to Quarkus. However, if you want it to be processed through the QuarkusErrorHandler you'd want to disable the default exception mapper.

@Karm
Copy link
Member

Karm commented Sep 28, 2022

Hello,

I am sorry I am coming late to the party. I read the comments and it's clearly unrelated to AWT (and not related to native either I think).
I can offer an opinion as a Quarkus user: When such a disastrous exception happens, I want to see the path that caused it in the log by default.

It is fine to have the power to fine tune it, to mute it, to consume it etc., but the default should be rather gruff and simple IMHO.

@gsmet

Also, the tests are failing in integration-tests/no-awt but only in native (maybe they are only run in native?)

Yes. This test tests the UX in a situation when user clearly attempts to use something that would require the AWT extension but it is not loaded, i.e. a friendly, instructive error must be logged. No point to run it in JVM mode.

@gsmet
Copy link
Member Author

gsmet commented Sep 28, 2022

@Karm yeah thanks, we figured it out :). I'm trying an upgrade to RESTEasy 6.2.0.Final and will see how it goes.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Status: Done
Development

Successfully merging a pull request may close this issue.

5 participants