Content negotiation issue in 2.0.12 when multiple Accept headers #569

Closed
vmassol opened this Issue Apr 16, 2012 · 12 comments

Comments

Projects
None yet
5 participants
@vmassol

vmassol commented Apr 16, 2012

Hi,

We have upgraded to 2.0.12 (but the issue could also been there before) and we have found a regression.

We're making a POST to

http://localhost:8080/xwiki/rest/wikis/xwiki/spaces/Main/pages/Spaces?method=PUT

with the following headers (at least that's what firebug says)

Accept  text/javascript, text/html, application/xml, text/xml, */*
Accept-Encoding gzip, deflate
Accept-Language en-us,en;q=0.5
Cache-Control   no-cache
Connection  keep-alive
Content-Length  22
Content-Type    application/x-www-form-urlencoded; charset=UTF-8
Cookie  [...]
Host    localhost:8080
Pragma  no-cache
Referer http://localhost:8080/xwiki/bin/view/XWiki/HierarchyMacro
User-Agent  Mozilla/5.0 (X11; Ubuntu; Linux i686; rv:11.0) Gecko/20100101 Firefox/11.0
X-Prototype-Version 1.6.1
X-Requested-With    XMLHttpRequest

And we get a 500 server error as a response.

This very same code was working before.

We get this in the logs:

Apr 16, 2012 5:28:18 PM org.restlet.ext.jaxrs.internal.util.ExceptionHandler noMessageBodyWriter
WARNING: No message body writer found for class class org.xwiki.rest.model.jaxb.Page, genericType class org.xwiki.rest.model.jaxb.Page; response media type should be: text/javascript; accepted media types are: [[text/javascript, text/html, application/xml, text/xml, */*]]

Apparently it tried to find a messagebodywriter for "text/html"
(org.restlet.ext.jaxrs.JaxRsRestlet.determineMediaType(MediaType, ResourceMethod, Class<?>, Type) is finding text/html for some reason)

We have some other code which sends the same POST but with only a single Accept header to application/xml and that one seems to be working.

So we're wondering if the regression is caused when several Accept header values are sent.

Note also that Fabio says it makes him think of http://restlet.tigris.org/issues/show_bug.cgi?id=730 which he reported a long time ago.

Thanks

@ghost ghost assigned thboileau Apr 16, 2012

@fmancinelli

This comment has been minimized.

Show comment Hide comment
@fmancinelli

fmancinelli Apr 16, 2012

An excerpt of a discussion in our XWiki chat:

[19:03:16 CEST] Fabio Mancinelli: Imho it's again this bug: http://restlet.tigris.org/issues/show_bug.cgi?id=730 ...

curl http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> WORKS
curl -H "Accept: application/xml" http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> WORKS
curl -H "Accept: text/html" http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> EXCEPTION (No messagebody writer, which is correct)
curl -H "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" -> EXCEPTION

The "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" is what my browser sends. It contains application/xml as a valid alternative but it seems that Restlet ignores it and stops examining alternatives at the first one (i.e., text/html) correctly reporting an exception because there is no text/html body writer registered

It's to be noted that here we are talking about the JAXRS extension... Maybe the bug Jerome is talking is fixed in Restlet but the JAXRS module does something different.
[19:04:38 CEST] Fabio Mancinelli: so maybe there are strange interactions between Restlet Core and JAXRS extension that make this behaviour appear even though it was supposed to be fixed
[19:08:58 CEST] Anca Luca: so, i'm debugging
[19:09:04 CEST] Anca Luca: since debugging is fun
[19:09:04 CEST] Anca Luca: and
[19:09:38 CEST] Anca Luca: the determineMediaType function I was talking about earlier works fine
[19:09:39 CEST] Anca Luca: but
[19:10:09 CEST] Anca Luca: there is a line line this in that function:

        p = providers.writerSubSet(entityClass, genericReturnType)
                .getAllProducibleMediaTypes();

[19:10:18 CEST] Anca Luca: which returns */* as producible media type
[19:10:53 CEST] Anca Luca: so the determineMediaType function actually finds that the first accepted media type (text/html) is also producible (since that list says that it can produce */*)
[19:11:06 CEST] Anca Luca: which is why it returns text/html
[19:11:10 CEST] Anca Luca: which is correct
[19:11:30 CEST] Anca Luca: since the first media type accepted by the client which is also producible should be returned (to make a proper negociation)
[19:11:53 CEST] Anca Luca: now, i need to find out why that function there says that it can produce */* since it's so awfully false
[19:21:05 CEST] Anca Luca: from what it seems org.restlet.ext.jaxrs.internal.provider.ConverterProvider is responsible for that */*
[19:21:27 CEST] Anca Luca: which is found as a response body writer and it declares that it can produce /
[19:36:14 CEST] Anca Luca: and then further on org.restlet.ext.jaxrs.internal.wrappers.provider.MessageBodyWriterSubSet.getBestWriter(MediaType, Annotation[], SortedMetadata<MediaType>)
which is trying to find the writer according to the determined Media Type, it's found that the xwiki resource (of type org.xwiki.rest.model.jaxb.Xwiki in my debugging) is not writable on the Converter body writer, hence the exception
[19:37:51 CEST] Fabio Mancinelli: I will copy paste my and yours messages from this discussion in the comment
[19:38:00 CEST] Anca Luca: ok, thanks a lot
[19:39:46 CEST] Anca Luca: it seems a bit hasty to me to get the producible media types like this:

p = providers.writerSubSet(entityClass, genericReturnType)
.getAllProducibleMediaTypes(); 

I would say that the writable check should be done at this point, before comparing this list with the accepted media types...

An excerpt of a discussion in our XWiki chat:

[19:03:16 CEST] Fabio Mancinelli: Imho it's again this bug: http://restlet.tigris.org/issues/show_bug.cgi?id=730 ...

curl http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> WORKS
curl -H "Accept: application/xml" http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> WORKS
curl -H "Accept: text/html" http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> EXCEPTION (No messagebody writer, which is correct)
curl -H "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" -> EXCEPTION

The "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" is what my browser sends. It contains application/xml as a valid alternative but it seems that Restlet ignores it and stops examining alternatives at the first one (i.e., text/html) correctly reporting an exception because there is no text/html body writer registered

It's to be noted that here we are talking about the JAXRS extension... Maybe the bug Jerome is talking is fixed in Restlet but the JAXRS module does something different.
[19:04:38 CEST] Fabio Mancinelli: so maybe there are strange interactions between Restlet Core and JAXRS extension that make this behaviour appear even though it was supposed to be fixed
[19:08:58 CEST] Anca Luca: so, i'm debugging
[19:09:04 CEST] Anca Luca: since debugging is fun
[19:09:04 CEST] Anca Luca: and
[19:09:38 CEST] Anca Luca: the determineMediaType function I was talking about earlier works fine
[19:09:39 CEST] Anca Luca: but
[19:10:09 CEST] Anca Luca: there is a line line this in that function:

        p = providers.writerSubSet(entityClass, genericReturnType)
                .getAllProducibleMediaTypes();

[19:10:18 CEST] Anca Luca: which returns */* as producible media type
[19:10:53 CEST] Anca Luca: so the determineMediaType function actually finds that the first accepted media type (text/html) is also producible (since that list says that it can produce */*)
[19:11:06 CEST] Anca Luca: which is why it returns text/html
[19:11:10 CEST] Anca Luca: which is correct
[19:11:30 CEST] Anca Luca: since the first media type accepted by the client which is also producible should be returned (to make a proper negociation)
[19:11:53 CEST] Anca Luca: now, i need to find out why that function there says that it can produce */* since it's so awfully false
[19:21:05 CEST] Anca Luca: from what it seems org.restlet.ext.jaxrs.internal.provider.ConverterProvider is responsible for that */*
[19:21:27 CEST] Anca Luca: which is found as a response body writer and it declares that it can produce /
[19:36:14 CEST] Anca Luca: and then further on org.restlet.ext.jaxrs.internal.wrappers.provider.MessageBodyWriterSubSet.getBestWriter(MediaType, Annotation[], SortedMetadata<MediaType>)
which is trying to find the writer according to the determined Media Type, it's found that the xwiki resource (of type org.xwiki.rest.model.jaxb.Xwiki in my debugging) is not writable on the Converter body writer, hence the exception
[19:37:51 CEST] Fabio Mancinelli: I will copy paste my and yours messages from this discussion in the comment
[19:38:00 CEST] Anca Luca: ok, thanks a lot
[19:39:46 CEST] Anca Luca: it seems a bit hasty to me to get the producible media types like this:

p = providers.writerSubSet(entityClass, genericReturnType)
.getAllProducibleMediaTypes(); 

I would say that the writable check should be done at this point, before comparing this list with the accepted media types...

@thboileau

This comment has been minimized.

Show comment Hide comment
@thboileau

thboileau Apr 16, 2012

Member

Yes, you're right, the ConverterProvider returns a weird list of produced media types (/). There is a kind of mismatch between a logic based on @Produces annotation, and the other based on the discovery of converters...

Member

thboileau commented Apr 16, 2012

Yes, you're right, the ConverterProvider returns a weird list of produced media types (/). There is a kind of mismatch between a logic based on @Produces annotation, and the other based on the discovery of converters...

@jlouvel

This comment has been minimized.

Show comment Hide comment
@jlouvel

jlouvel Apr 17, 2012

Member

It seems that the JAX-RS 1.1 spec isn't precisely implemented regarding the media type selection:
http://jsr311.java.net/nonav/releases/1.1/spec/spec3.html#x3-380003.8

Currently looking into fixing this...

Member

jlouvel commented Apr 17, 2012

It seems that the JAX-RS 1.1 spec isn't precisely implemented regarding the media type selection:
http://jsr311.java.net/nonav/releases/1.1/spec/spec3.html#x3-380003.8

Currently looking into fixing this...

@jlouvel

This comment has been minimized.

Show comment Hide comment
@jlouvel

jlouvel Apr 17, 2012

Member

I've been able to reproduce the issue by adding two Accept preferences to an existing test case (PersonsTest), then to have it pass by making the media type selection smarter.

BEFORE:

List m = new ArrayList();
for (MediaType acc : a)
for (MediaType prod : pSorted)
if (prod.isCompatible(acc))
m.add(MediaType.getMostSpecific(prod, acc));

AFTER:

List m = new ArrayList();

    // First test equality (ideal)
    for (MediaType a1 : a) {
        for (MediaType p1 : p) {
            if (a1.equals(p1)) {
                m.add(a1);
            }
        }
    }

    // Otherwise test inclusion (good)
    if (m.isEmpty()) {
        for (MediaType a1 : a) {
            for (MediaType p1 : p) {
                if (a1.includes(p1)) {
                    m.add(MediaType.getMostSpecific(a1, p1));
                }
            }
        }
    }

    // Finally test compatibility (most flexible)
    if (m.isEmpty()) {
        for (MediaType a1 : a) {
            for (MediaType p1 : p) {
                if (a1.isCompatible(p1)) {
                    m.add(MediaType.getMostSpecific(a1, p1));
                }
            }
        }
    }

It seems to work nicely and all test cases still pass. I've committed it in branches 2.0/2.1/master. New snapshots should come soon. Could you test again?

Member

jlouvel commented Apr 17, 2012

I've been able to reproduce the issue by adding two Accept preferences to an existing test case (PersonsTest), then to have it pass by making the media type selection smarter.

BEFORE:

List m = new ArrayList();
for (MediaType acc : a)
for (MediaType prod : pSorted)
if (prod.isCompatible(acc))
m.add(MediaType.getMostSpecific(prod, acc));

AFTER:

List m = new ArrayList();

    // First test equality (ideal)
    for (MediaType a1 : a) {
        for (MediaType p1 : p) {
            if (a1.equals(p1)) {
                m.add(a1);
            }
        }
    }

    // Otherwise test inclusion (good)
    if (m.isEmpty()) {
        for (MediaType a1 : a) {
            for (MediaType p1 : p) {
                if (a1.includes(p1)) {
                    m.add(MediaType.getMostSpecific(a1, p1));
                }
            }
        }
    }

    // Finally test compatibility (most flexible)
    if (m.isEmpty()) {
        for (MediaType a1 : a) {
            for (MediaType p1 : p) {
                if (a1.isCompatible(p1)) {
                    m.add(MediaType.getMostSpecific(a1, p1));
                }
            }
        }
    }

It seems to work nicely and all test cases still pass. I've committed it in branches 2.0/2.1/master. New snapshots should come soon. Could you test again?

@fmancinelli

This comment has been minimized.

Show comment Hide comment
@fmancinelli

fmancinelli Apr 17, 2012

We're almost there...

I have retried the four "curls" I did yesterday and I think that something is still wrong:

curl http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> FAILS
curl -H "Accept: application/xml" http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> WORKS
curl -H "Accept: text/html" http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> FAILS (No messagebody writer, which is correct)
curl -H "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" -> WORKS

The first curl sends an Accept: */* header, so I would have expected some XML to be returned.

We're almost there...

I have retried the four "curls" I did yesterday and I think that something is still wrong:

curl http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> FAILS
curl -H "Accept: application/xml" http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> WORKS
curl -H "Accept: text/html" http://localhost:8080/xwiki-debug-eclipse/rest/wikis -> FAILS (No messagebody writer, which is correct)
curl -H "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8" -> WORKS

The first curl sends an Accept: */* header, so I would have expected some XML to be returned.

@lucaa

This comment has been minimized.

Show comment Hide comment
@lucaa

lucaa Apr 17, 2012

The first curl of Fmancinelli fails with

Apr 17, 2012 4:52:52 PM org.restlet.ext.jaxrs.internal.util.ExceptionHandler noMessageBodyWriter
WARNING: No message body writer found for class org.xwiki.rest.model.jaxb.Wikis(genericType is class  org.xwiki.rest.model.jaxb.Wikis); response media type should be: application/octet-stream; accepted media types are: [[*/*]]

which is correct because there is no application/octet-stream writer for that resource, afaik.

lucaa commented Apr 17, 2012

The first curl of Fmancinelli fails with

Apr 17, 2012 4:52:52 PM org.restlet.ext.jaxrs.internal.util.ExceptionHandler noMessageBodyWriter
WARNING: No message body writer found for class org.xwiki.rest.model.jaxb.Wikis(genericType is class  org.xwiki.rest.model.jaxb.Wikis); response media type should be: application/octet-stream; accepted media types are: [[*/*]]

which is correct because there is no application/octet-stream writer for that resource, afaik.

@lucaa

This comment has been minimized.

Show comment Hide comment
@lucaa

lucaa Apr 17, 2012

Actually, the change you made, Jlouvel, has a little glitch:
it should not test m.isEmpty() after the first match (the 'ideal' case as you named it).

Because what happens in our case (for the bug above) is that: curl sends

*/*

, and the first test ('ideal') finds the ConverterProvider that provides

*/* 

so m will contain

*/*

. All other loops will not be entered, since m is not empty so the final m will contain only

*/*. 

then at step 8 in the code of determineMediaType, when the first concrete media type is searched for, none will be found, so application octet stream will be returned by step 9.

I think removing the isEmpty() test would fix it: m will be filled with all compatible media types, ordered by which is the "most ideal", and then at step 8 the first concrete one will be returned.

lucaa commented Apr 17, 2012

Actually, the change you made, Jlouvel, has a little glitch:
it should not test m.isEmpty() after the first match (the 'ideal' case as you named it).

Because what happens in our case (for the bug above) is that: curl sends

*/*

, and the first test ('ideal') finds the ConverterProvider that provides

*/* 

so m will contain

*/*

. All other loops will not be entered, since m is not empty so the final m will contain only

*/*. 

then at step 8 in the code of determineMediaType, when the first concrete media type is searched for, none will be found, so application octet stream will be returned by step 9.

I think removing the isEmpty() test would fix it: m will be filled with all compatible media types, ordered by which is the "most ideal", and then at step 8 the first concrete one will be returned.

jlouvel pushed a commit that referenced this issue Apr 17, 2012

jlouvel pushed a commit that referenced this issue Apr 17, 2012

jlouvel pushed a commit that referenced this issue Apr 17, 2012

jlouvel pushed a commit that referenced this issue Apr 17, 2012

@jlouvel

This comment has been minimized.

Show comment Hide comment
@jlouvel

jlouvel Apr 17, 2012

Member

Following the advice of @lucaa I've been able to fix the remaining issue. A regression test case has also been added. New 2.0.13 version will be released tonight or tomorrow.

I'm closing this issue for now. Feel free to comment/reopen if needed.

Member

jlouvel commented Apr 17, 2012

Following the advice of @lucaa I've been able to fix the remaining issue. A regression test case has also been added. New 2.0.13 version will be released tonight or tomorrow.

I'm closing this issue for now. Feel free to comment/reopen if needed.

@thboileau

This comment has been minimized.

Show comment Hide comment
@thboileau

thboileau Apr 18, 2012

Member

Hello all, Restlet 2.0.13 is available right now.

Member

thboileau commented Apr 18, 2012

Hello all, Restlet 2.0.13 is available right now.

@vmassol

This comment has been minimized.

Show comment Hide comment
@vmassol

vmassol Apr 18, 2012

great, thanks a lot again!

vmassol commented Apr 18, 2012

great, thanks a lot again!

@fmancinelli

This comment has been minimized.

Show comment Hide comment
@fmancinelli

fmancinelli Apr 18, 2012

Thanks!

Little question... Do you have a policy for security-oriented bugs? We discovered a vulnerability and I don't know how to proceed.

Thanks!

Little question... Do you have a policy for security-oriented bugs? We discovered a vulnerability and I don't know how to proceed.

@thboileau

This comment has been minimized.

Show comment Hide comment
@thboileau

thboileau Apr 18, 2012

Member

Hello Fabio,
you can contact us directly.
Best regards,
Thierry Boileau

Member

thboileau commented Apr 18, 2012

Hello Fabio,
you can contact us directly.
Best regards,
Thierry Boileau

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment