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!!
What can happen between the inbound request filter output the the call to
getTarget?
(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
>