On Jul 23, 2009, at 11:40 AM, Paul Sandoz wrote:
> 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.
>
I just added some logging to the trunk. It is available from the maven
repo as well using 1.1.2-ea-SNAPSHOT.
Paul.
> 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
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_jersey.dev.java.net
> For additional commands, e-mail: users-help_at_jersey.dev.java.net
>