On Jul 23, 2009, at 10:56 AM, Christopher Schmidt wrote:
> Hi Paul, we've made some further investigations:
>
> The below text shows the logger output (client logger is on, server
> request
> and response logger is on). I can see the request on both sides and a
> response (on client side) without content type. We put some logging
> into the
> method getTarget, but it is not called!!
>
OK.
> What can happen between the inbound request filter output the the
> call to
> getTarget?
>
If a RuntimeException is thrown, and it is not mapped by Jersey using
an ExceptionMapper to a Response, then that RuntimeException is re-
thrown to the container. In your case the Tomcat server, so you may
see something in the Tomcat logs reflecting this.
One way you can check in Jersey if any RuntimeException is thrown is
to register the following ExceptionMapper:
@Provider
public class RuntimeExceptionMapper implements
ExceptionMapper<RuntimeException> {
public Response toResponse(RuntimeException ex) {
// Mapping a runtime exception
ex.printStackTrace();
return Response.status(500).entity(ex.toString()).build();
}
}
Apart from the logging filter do you have:
1) additional request or response filters configured (including
resource-based request/response filters) that
may throw any exceptions; or
2) one or more ExceptionMapper instances registered?
The confusing aspect of this is a 200 response is returned. If this
response is set by Jersey then, from looking at the code, there are
two possibles way i can see how this can occur:
1) A response filter throws an exception that gets mapped to a 200
response. That response filter
could be a filter registered to occur *before* the logging
filter; or
2) as a specialization of 1) an ExceptionMapper is registered to trap
the exception thrown in 1) and the
toResponse method returns null, see:
https://jsr311.dev.java.net/nonav/javadoc/javax/ws/rs/ext/ExceptionMapper.html
#toResponse%28E%29
I think we also need to check Tomcat logging to see if it received a
RuntimeException, also we should check the AspectJ configuration to
see if that is throwing a RuntimeException.
I think i need to add some logging statements to Jersey when
exceptions are mapped or a RuntimeException is re-thrown to the
container. If i do that you can try 1.1.2-ea-SNAPSHOT.
Thanks for your persistence with this,
Paul
> (We are using tomcat 6.0.20, jersey 1.1.1-ea and some aspects
> (AspectJ) on
> methods)
>
> Regards Christopher
>
>
> 17487 * Out-bound request
> 17487 > GET
> http://as2-srv-ts:8080/OspWS/V1/Target/target/object/953111100000030
> 17487 > Authorization: Basic b3NyOmNvcw==
> 17487 > Accept: application/xml
> 17487 >
>
>
>
> 182431 * In-bound request received
> 182431 > GET
> http://as2-srv-ts:8080/OspWS/V1/Target/target/object/953111100000030
> 182431 > authorization: Basic b3NyOmNvcw==
> 182431 > connection: keep-alive
> 182431 > cache-control: no-cache
> 182431 > host: as2-srv-ts:8080
> 182431 > user-agent: Java/1.6.0_07
> 182431 > pragma: no-cache
> 182431 > accept: application/xml
> 182431 >
>
>
> 17487 < 200
> 17487 < Transfer-Encoding: chunked
> 17487 < Server: Apache-Coyote/1.1
> 17487 < Date: Sat, 18 Jul 2009 06:42:07 GMT
> 17487 <
> 17487 * In-bound response
>
> ERROR [Thread-648] .eads.web.rrs.DataManager Unable to update Track
> com.eads.ospws.client.service.OspWSServiceException: Failure to
> process the
> HTTP request or HTTP response
> in Class:
> com.eads.ospws.client.service.BorderEventClientService
> in Method: getTarget
> at
> com
> .eads
> .ospws.client.service.BorderEventClientService.getTarget_aroundBody1
> 9$advice(BorderEventClientService.java:31)
> at
> com
> .eads
> .ospws.client.service.BorderEventClientService.getTarget(BorderEvent
> ClientService.java:1)
> at
> com
> .eads.web.rrs.WebObjectFactory.updateLocation(WebObjectFactory.java:
> 82)
> at com.eads.web.rrs.DataManager.updateTrack(DataManager.java:
> 745)
> at
> com.eads.web.rrs.DataManager.fireNotification(DataManager.java:663)
> at
> com
> .eads
> .web.rrs.notification.NotificationQueue.run(NotificationQueue.java:4
> 4)
> Caused by: com.sun.jersey.api.client.ClientHandlerException: A
> message body
> reader for Java type, class com.eads.ospws.resource.jaxb.Target, and
> MIME
> media type,
> application/octet-stream, was not found
> at
> com
> .sun.jersey.api.client.ClientResponse.getEntity(ClientResponse.java:
> 255)
> at
> com
> .sun.jersey.api.client.ClientResponse.getEntity(ClientResponse.java:
> 220)
> at
> com.sun.jersey.api.client.WebResource.handle(WebResource.java:561)
> at
> com.sun.jersey.api.client.WebResource.access$300(WebResource.java:69)
> at
> com.sun.jersey.api.client.WebResource$Builder.get(WebResource.java:
> 451)
> at
> com
> .eads
> .ospws.client.service.BorderEventClientService.getTarget_aroundBody1
> 8(BorderEventClientService.java:195)
> at
> com
> .eads
> .ospws.client.service.BorderEventClientService.getTarget_aroundBody1
> 9$advice(BorderEventClientService.java:29)
> ... 5 more
>
> INFO [Thread-648] ication.NotificationQueue null processed at
> 08:44:49:0964
> after 30695ms
> INFO [Thread-648] ication.NotificationQueue null received at
> 08:44:49:0964
> ERROR [Thread-648] rrs.javascript.JavaScript JSCallCollection
> alleady in
> progress
> DEBUG [Thread-648] ice.CatchJerseyExceptions Calling ClientService
> with
> Thread ID: 1884
> DEBUG [Thread-648] ice.CatchJerseyExceptions Calling ClientService
> with
> Thread ID: 1884
>
>
>
> 17488 * Out-bound request
> 17488 > GET
> http://as2-srv-ts:8080/OspWS/V1/Target/target/object/953111100000034
> 17488 > Authorization: Basic b3NyOmNvcw==
> 17488 > Accept: application/xml
> 17488 >
> 182432 * In-bound request received
> 182432 > GET http://as2-srv-ts:8080/OspWS/V1/Target/target/object/95
>
>
> Am 15.07.09 10:19 schrieb "Paul Sandoz" unter <Paul.Sandoz_at_Sun.COM>:
>
>>
>> On Jul 14, 2009, at 7:44 PM, Christopher Schmidt wrote:
>>
>>> Hi Paul, yes the response should be XML.
>>>
>>> I added your mentioned response filter to the server side.
>>>
>>> What happens is, that there is no "out bound response sent" logging
>>> text in case of the wrong response
>>>
>>
>> Oh, i did not expect that!
>>
>> Just double checking: are you sure that there is a mis-correlation
>> between the "id" values (the numbers at the beginning) that are
>> logged
>> for the request/response on the server side ? i.e. the same id value
>> is used for the request and its response.
>>
>>
>>> There must be something between the execution of the resource method
>>> and the call of the LoggingFilter - right?
>>>
>>
>> Yes. Do you know if your resource method "getTarget" is getting
>> invoked?
>>
>> I am wondering if there is some RuntimeException when in the Jersey
>> layer which is then getting passed to Tomcat because Jersey cannot
>> map
>> it. Is there any addition logging output from Tomcat indicating that
>> to be the case?
>>
>> Two things:
>>
>> 1) If possible could you send me the log files?
>>
>> 2) Is is possible to change from Tomcat to say GF, or a new version
>> of
>> Tomcat and see if you get the same error?
>>
>> Paul.
>>
>>> Regards Christopher
>>>
>>>
>>>
>>> Am 10.07.2009 um 16:10 schrieb Paul Sandoz:
>>>
>>>>
>>>> On Jul 10, 2009, at 1:38 PM, Christopher Schmidt wrote:
>>>>
>>>>> Hi Paul, we added the filter. The server resource is defined as my
>>>>> example below (just a different URL and jaxb type).
>>>>> And the exception happens more often if we are increasing the
>>>>> threads accessing the server.
>>>>>
>>>>
>>>> OK, that implies some form of race condition.
>>>>
>>>>
>>>>> This is the request:
>>>>>
>>>>> 4 * Out-bound request
>>>>> 4 > GET http://as2-srv-ts:8080/OspWS/V1/BorderGuardOrganisation/
>>>>> sector/ids/
>>>>> 4 > Authorization: Basic b3NyOmNvcw==
>>>>> 4 > Accept: application/xml
>>>>> 4 >
>>>>>
>>>>> This is the received request on server side:
>>>>>
>>>>> 75 * In-bound request received
>>>>> 75 > GET http://as2-srv-ts:8080/OspWS/V1/BorderGuardOrganisation/
>>>>> sector/ids/
>>>>> 75 > authorization: Basic b3NyOmNvcw==
>>>>> 75 > connection: keep-alive
>>>>> 75 > cache-control: no-cache
>>>>> 75 > host: as2-srv-ts:8080
>>>>> 75 > user-agent: Java/1.6.0_07
>>>>> 75 > pragma: no-cache
>>>>> 75 > accept: application/xml
>>>>> 75 >
>>>>>
>>>>> And this is the received (wrong) response (I've shortened the
>>>>> binary stuff):
>>>>>
>>>>
>>>> We need to log the out bound response as sent from the Jersey
>>>> server side to the client to ascertain if there is any issue at the
>>>> Jersey level:
>>>>
>>>> <init-param>
>>>> <param-
>>>> name>com.sun.jersey.spi.container.ContainerResponseFilters</param-
>>>> name>
>>>> <param-
>>>> value>com.sun.jersey.api.container.filter.LoggingFilter</param-
>>>> value>
>>>> </init-param>
>>>>
>>>>
>>>>
>>>>> 4 < 200
>>>>> 4 < Transfer-Encoding: chunked
>>>>> 4 < Server: Apache-Coyote/1.1
>>>>> 4 < Date: Fri, 10 Jul 2009 11:20:06 GMT
>>>>> 4 <
>>>>>
>>>>> Cb?6???O?ll?0?&?x?9?n???eĀ??w??1??(i6d?3?R?????=?Z?^?
>>>>> ??^??? Ҙ?{?}+
>>>>> ?m OB??TM?Ed???8Rr?-fߺ??/?????ѱC???/?????ɎCw?e????
>>>>> QnJa???)K?D1?<Pj
>>>>> ???[?wPL??d??Q?????荌???E?ܿ?]_4?/??vkp??}|B?r??KvN3z?=???
>>>>> k ???
>>>>> p4?As'4$??\???q???~?pwn????%??????<jt?»?9,?:E{??֪?p?v/'???ir?
>>>>> ^??1p??y???C?k?W?X~u?l? ??g%O
>>>>> HfITE?VHS? Y?_o?
>>>>>
>>>>
>>>> Is that XML ?!? in addition to the absence of certain headers it
>>>> looks like there is something very wrong with the above entity
>>>> body.
>>>>
>>>> Paul.
>>>>
>>>>> 4 * In-bound response
>>>>> ERROR [Thread-337] .eads.web.rrs.DataManager Unable to load
>>>>> Sectors/RRSs
>>>>> com.eads.ospws.client.service.OspWSServiceException: Failure to
>>>>> process the HTTP request or HTTP response
>>>>> in Class: com.eads.ospws.client.service.BorderEventClientService
>>>>> in Method: getSectors
>>>>> at
>>>>> com
>>>>> .eads
>>>>> .ospws
>>>>> .client
>>>>> .service
>>>>> .BorderEventClientService
>>>>> .getSectors_aroundBody1$advice(BorderEventClientService.java:25)
>>>>> at
>>>>> com
>>>>> .eads
>>>>> .ospws
>>>>> .client
>>>>> .service
>>>>> .BorderEventClientService
>>>>> .getSectors(BorderEventClientService.java:
>>>>> 1)
>>>>> at com.eads.web.rrs.DataManager.loadSectors(DataManager.java:282)
>>>>> at com.eads.web.rrs.InitialDataLoader.run(InitialDataLoader.java:
>>>>> 28)
>>>>> at java.lang.Thread.run(Thread.java:619)
>>>>> Caused by: com.sun.jersey.api.client.ClientHandlerException: A
>>>>> message body reader for Java type, class
>>>>> com.eads.ospws.resource.jaxb.IdArray, and MIME media type,
>>>>> application/octet-stream, was not found
>>>>> at
>>>>> com
>>>>> .sun
>>>>> .jersey.api.client.ClientResponse.getEntity(ClientResponse.java:
>>>>> 255)
>>>>> at
>>>>> com
>>>>> .sun
>>>>> .jersey.api.client.ClientResponse.getEntity(ClientResponse.java:
>>>>> 220)
>>>>> at com.sun.jersey.api.client.WebResource.handle(WebResource.java:
>>>>> 561)
>>>>> at com.sun.jersey.api.client.WebResource.access
>>>>> $300(WebResource.java:69)
>>>>> at com.sun.jersey.api.client.WebResource
>>>>> $Builder.get(WebResource.java:451)
>>>>> at
>>>>> com
>>>>> .eads
>>>>> .ospws
>>>>> .client
>>>>> .service
>>>>> .BorderEventClientService
>>>>> .getSectors_aroundBody0(BorderEventClientService.java:59)
>>>>> at
>>>>> com
>>>>> .eads
>>>>> .ospws
>>>>> .client
>>>>> .service
>>>>> .BorderEventClientService
>>>>> .getSectors_aroundBody1$advice(BorderEventClientService.java:23)
>>>>> ... 4 more
>>>>>
>>>>>
>>>>> Regards Christopher
>>>>>
>>>>> Am 10.07.09 10:48 schrieb "Paul Sandoz" unter
>>>>> <Paul.Sandoz_at_Sun.COM>:
>>>>>
>>>>>>
>>>>>> On Jul 10, 2009, at 8:22 AM, Christopher Schmidt wrote:
>>>>>>
>>>>>>> Hi Paul, we are using also a Servlet as a client.
>>>>>>
>>>>>> OK, i thought so.
>>>>>>
>>>>>>
>>>>>>> The servers logging is configured like this:
>>>>>>>
>>>>>>> <init-param>
>>>>>>> <param-
>>>>>>> name>com.sun.jersey.spi.container.ContainerRequestFilters</
>>>>>>> param-
>>>>>>> name>
>>>>>>> <param-
>>>>>>> value>com.sun.jersey.api.container.filter.LoggingFilter</param-
>>>>>>> value>
>>>>>>> </init-param>
>>>>>>>
>>>>>>
>>>>>> Can you also add:
>>>>>>
>>>>>> <init-param>
>>>>>> <param-
>>>>>> name>com.sun.jersey.spi.container.ContainerResponseFilters</
>>>>>> param-
>>>>>> name>
>>>>>> <param-
>>>>>> value>com.sun.jersey.api.container.filter.LoggingFilter</param-
>>>>>> value>
>>>>>> </init-param>
>>>>>>
>>>>>> So that the responses get logged?
>>>>>>
>>>>>>
>>>>>>> Can I do something like this for your mentioned client filter as
>>>>>>> well?
>>>>>>>
>>>>>>
>>>>>> Yes.
>>>>>>
>>>>>> Client c = ...
>>>>>> c.addFilter(
>>>>>> new com.sun.jersey.api.client.filter.LoggingFilter());
>>>>>>
>>>>>>
>>>>>> Hopefully that should give us additional information to close in
>>>>>> on where the problem is located.
>>>>>>
>>>>>> Paul.
>>>>>>
>>>>>>> Regards Christopher
>>>>>>>
>>>>>>>
>>>>>>> Am 09.07.09 13:18 schrieb "Paul Sandoz" unter
>>>>>>> <Paul.Sandoz_at_Sun.COM>:
>>>>>>>
>>>>>>>
>>>>>>>> Hi Christopher,
>>>>>>>>
>>>>>>>> Given that this happens about 0.01 % of the time i am wondering
>>>>>>>> if there is a subtle race condition in the Tomcat server when
>>>>>>>> setting response headers. All Jersey does is pass it's headers
>>>>>>>> over to the servlet response.
>>>>>>>>
>>>>>>>> Do you have also logging of the "Out-bound response sent" from
>>>>>>>> the server to the client? it would be useful to know if the
>>>>>>>> content-type was set correctly by Jersey.
>>>>>>>>
>>>>>>>> You can also ad logging to the client side as well:
>>>>>>>>
>>>>>>>>
>>>>>>>> https://jersey.dev.java.net/nonav/apidocs/1.1.0-ea/jersey/com/sun/jersey
>>>>>>>> /api/client/filter/LoggingFilter.html
>>>>>>>>
>>>>>>>> Maybe some tomcat-level logging of response headers would also
>>>>>>>> be useful?
>>>>>>>>
>>>>>>>> Paul.
>>>>>>>>
>>>>>>>> On Jul 9, 2009, at 9:40 AM, Christopher Schmidt wrote:
>>>>>>>>
>>>>>>>>
>>>>>>>>> Hello, sometimes when I access the following resource method
>>>>>>>>> (TargetEnh is a subclassed JAXB object):
>>>>>>>>>
>>>>>>>>> @GET @Produces("application/xml") @Path("target/object/
>>>>>>>>> {tId}/") @RequiresMorphSession public Target
>>>>>>>>> getTarget(@PathParam("tId") String tId) { ...
>>>>>>>>> return new TargetEnh(oi, getUser()); }
>>>>>>>>>
>>>>>>>>> With the following client code:
>>>>>>>>>
>>>>>>>>> return getTargetResource().path("target/object/" +
>>>>>>>>> targetId).header("Authorization",
>>>>>>>>> user
>>>>>>>>> .userCredentials
>>>>>>>>> ()).accept
>>>>>>>>> ( MediaType.APPLICATION_XML).get(Target.class);
>>>>>>>>>
>>>>>>>>> I get sometimes the following exception.
>>>>>>>>>
>>>>>>>>> 115131 * In-bound request received
>>>>>>>>> 115131 > GET http://as2-srv-ts:8080/OspWS/V1/Target/target/
>>>>>>>>> object/953111100000169
>>>>>>>>> 115131 > authorization: Basic b3NyOmNvcw==
>>>>>>>>> 115131 > connection: keep-alive
>>>>>>>>> 115131 > cache-control: no-cache
>>>>>>>>> 115131 > host: as2-srv-ts:8080
>>>>>>>>> 115131 > user-agent: Java/1.6.0_07
>>>>>>>>> 115131 > pragma: no-cache
>>>>>>>>> 115131 > accept: application/xml
>>>>>>>>> 115131 >
>>>>>>>>> ERROR [Thread-156] .eads.web.rrs.DataManager
>>>>>>>>> <http://web.rrs.DataManager
>>>>>>>>>> <http://web.rrs.DataManager> Unable to update Track
>>>>>>>>> com.eads.ospws.client.service.OspWSServiceException: Failure
>>>>>>>>> to process the HTTP request or HTTP response
>>>>>>>>> in Class:
>>>>>>>>> com.eads.ospws.client.service.BorderEventClientService
>>>>>>>>> in Method: getTarget
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .eads
>>>>>>>>> .ospws
>>>>>>>>> .client
>>>>>>>>> .service
>>>>>>>>> .BorderEventClientService
>>>>>>>>> .getTarget_aroundBody19$advice(BorderEventClientService.java:
>>>>>>>>> 25)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .eads
>>>>>>>>> .ospws
>>>>>>>>> .client
>>>>>>>>> .service
>>>>>>>>> .BorderEventClientService
>>>>>>>>> .getTarget(BorderEventClientService.java:1)
>>>>>>>>> at com.eads.web.rrs.WebObjectFactory.updateLocation
>>>>>>>>> <http://web.rrs.WebObjectFactory.updateLocation
>>>>>>>>>> <http://web.rrs.WebObjectFactory.updateLocation>
>>>>>>>>> (WebObjectFactory.java:84)
>>>>>>>>> at com.eads.web.rrs.DataManager.updateTrack
>>>>>>>>> <http://web.rrs.DataManager.updateTrack
>>>>>>>>>> <http://web.rrs.DataManager.updateTrack> (DataManager.java:
>>>>>>>>> 865)
>>>>>>>>> at com.eads.web.rrs.DataManager.fireNotification
>>>>>>>>> <http://web.rrs.DataManager.fireNotification
>>>>>>>>>> <http://web.rrs.DataManager.fireNotification>
>>>>>>>>> (DataManager.java:784)
>>>>>>>>> at com.eads.web.rrs.notification.NotificationQueue.run
>>>>>>>>> <http://web.rrs.notification.NotificationQueue.run
>>>>>>>>>> <http://web.rrs.notification.NotificationQueue.run>
>>>>>>>>> (NotificationQueue.java:74)
>>>>>>>>> Caused by: com.sun.jersey.api.client.ClientHandlerException: A
>>>>>>>>> message body reader for Java type, class
>>>>>>>>> com.eads.ospws.resource.jaxb.Target, and MIME media type,
>>>>>>>>> application/octet-stream, was not found
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .jersey
>>>>>>>>> .api.client.ClientResponse.getEntity(ClientResponse.java:255)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .sun
>>>>>>>>> .jersey
>>>>>>>>> .api.client.ClientResponse.getEntity(ClientResponse.java:220)
>>>>>>>>> at
>>>>>>>>> com.sun.jersey.api.client.WebResource.handle(WebResource.java:
>>>>>>>>> 561)
>>>>>>>>> at com.sun.jersey.api.client.WebResource.access
>>>>>>>>> $300(WebResource.java:69)
>>>>>>>>> at com.sun.jersey.api.client.WebResource
>>>>>>>>> $Builder.get(WebResource.java:451)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .eads
>>>>>>>>> .ospws
>>>>>>>>> .client
>>>>>>>>> .service
>>>>>>>>> .BorderEventClientService
>>>>>>>>> .getTarget_aroundBody18(BorderEventClientService.java:194)
>>>>>>>>> at
>>>>>>>>> com
>>>>>>>>> .eads
>>>>>>>>> .ospws
>>>>>>>>> .client
>>>>>>>>> .service
>>>>>>>>> .BorderEventClientService
>>>>>>>>> .getTarget_aroundBody19$advice(BorderEventClientService.java:
>>>>>>>>> 23)
>>>>>>>>> ... 5 more
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> It seams to me that the response header does not contain a
>>>>>>>>> “content-type” field.
>>>>>>>>> This only happens about 3-10 times per day calling this GET
>>>>>>>>> method about 2 times per second.
>>>>>>>>>
>>>>>>>>> (using Tomcat 6, Jersey 1.0.3 on a linux 64bit system)
>>>>>>>>>
>>>>>>>>> Any suggestions?
>>>>>>>>>
>>>>>>>>> Best regards
>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: users-unsubscribe_at_jersey.dev.java.net
>>>> For additional commands, e-mail: users-help_at_jersey.dev.java.net
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe_at_jersey.dev.java.net
>>> For additional commands, e-mail: users-help_at_jersey.dev.java.net
>>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe_at_jersey.dev.java.net
>> For additional commands, e-mail: users-help_at_jersey.dev.java.net
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_jersey.dev.java.net
> For additional commands, e-mail: users-help_at_jersey.dev.java.net
>