Uploaded image for project: 'CXF'
  1. CXF
  2. CXF-7712

LoggingInInterceptor

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Later
    • Affects Version/s: 3.1.1, 3.1.15
    • Fix Version/s: None
    • Component/s: JAX-WS Runtime
    • Labels:
      None
    • Estimated Complexity:
      Unknown

      Description

      I am not  a pro working with CXF, but I can confidently say that there is some help required.

      Issue:

      After we migrated to CXF3.1.0 from 2.7.4 (along with Java8), we started observing that the payload response entity is not being read correctly and sent back calling service. Instead it's being sent back as java.io.SequenceInputStream (in case of errors >= 400) as per code exist in ClientProxyImpl.java CXF class.

      In case of success responses we have specific check exists (i.e., checkresponse() method for errors status >= 400) and if it is < 400, we get thru the readBody() method and read the response entity contents to send back the response. But in case of response codes >= 400, we don't have any associated response entity reading in current CXF 3.1.0 code to pick the payload correctly (this is happening because we now have LoggingInInterceptor->logInputSream() method doing bis=new SequenceInputStream(.....), which now have an object structure on Java8.

      In older versions we had bis=new InputStream(bos) in LoggingInInterceptor, when calling writingPayLoad(), so it was straightforward to get the response payload from ResponseImpl object contents (ref to my screenshots).

      The reason I request someone to help on this, because we process the detailed error message we get in case of 400 responses.

       

      Logs:

      2018-04-16 09:34:33,697 DEBUG [tomcat-http--6] {} org.springframework.integration.channel.DirectChannel - preSend on channel 'authorizeUserResponseRouter', message: GenericMessage [payload=java.io.SequenceInputStream@2dd8abaf, headers=

      {responseRootElement=authorizeUsersResponse, replyChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@7f2b737a, errorChannel=org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel@7f2b737a, id=dd33d939-0daa-0bc6-c578-d34aece33c4a, MESSAGE_INFORMATION_HOLDER=javax.xml.ws.Holder@68c33562, timestamp=1523889273697}

      ]
      -------------------------------------
      ID: 5
      Response-Code: 400
      Encoding: ISO-8859-1
      Content-Type: application/xml
      Headers:

      {connection=[close], content-type=[application/xml], Date=[Mon, 16 Apr 2018 14:34:33 GMT], exception=[User not eligible], Server=[Apache-Coyote/1.1], transfer-encoding=[chunked], x-security-app-name=[clientapp-rest:1.0.41-1599], x-security-correlation-id=[cccc4e4e-f7f3-4ba4-9b72-4d32538ecf02], x-security-host=[server001], x-security-msg-id=[bacb9976-ac58-4546-9379-1332e2530d00], x-security-msg-version=[1], x-security-response-code=[200], x-security-service-version=[1.0.41-1599], x-security-timestamp=[XXXXXXXXX3652]}

      Payload: <?xml version="1.0" encoding="UTF-8" standalone="yes"?><ErrorResponse xmlns="namespacev1"><title>Bad Request</title><code>422</code><message>User not eligible</message></ErrorResponse>
      --------------------------------------
      2018-04-16 09:34:33,662 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Invoking handleMessage on interceptor myapp.client.security.client.penta.HttpHeaderInInterceptor@696f1a06
      2018-04-16 09:34:33,666 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Invoking handleMessage on interceptor org.apache.cxf.jaxrs.client.spec.ClientResponseFilterInterceptor@452f892b
      2018-04-16 09:34:33,681 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Adding interceptor org.apache.cxf.ws.policy.ClientPolicyInFaultInterceptor@3201c39f to phase receive
      2018-04-16 09:34:33,681 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Adding interceptor org.apache.cxf.ws.policy.PolicyVerificationInFaultInterceptor@925feb4 to phase pre-invoke
      2018-04-16 09:34:33,681 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Adding interceptor org.apache.cxf.interceptor.LoggingInInterceptor@f56e35b to phase receive
      2018-04-16 09:34:33,681 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Adding interceptor org.apache.cxf.interceptor.ClientFaultConverter@38b4d45b to phase unmarshal
      2018-04-16 09:34:33,681 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Chain org.apache.cxf.phase.PhaseInterceptorChain@1cba32cd was created. Current flow:
      receive [ClientPolicyInFaultInterceptor, LoggingInInterceptor]
      unmarshal [ClientFaultConverter]
      pre-invoke [PolicyVerificationInFaultInterceptor]

      2018-04-16 09:34:33,681 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Invoking handleMessage on interceptor org.apache.cxf.ws.policy.ClientPolicyInFaultInterceptor@3201c39f
      2018-04-16 09:34:33,682 DEBUG [tomcat-http--6] {} org.apache.cxf.ws.policy.ClientPolicyInFaultInterceptor - conduit: conduit: class org.apache.cxf.transport.http.URLConnectionHTTPConduit538646526target: https://server001.myapp.com/v1/AuthorizationService/entitlements/authorizations
      2018-04-16 09:34:33,682 DEBUG [tomcat-http--6] {} org.apache.cxf.ws.policy.ClientPolicyInFaultInterceptor - ep: org.apache.cxf.ws.policy.EndpointPolicyImpl@6ed8d17
      2018-04-16 09:34:33,682 DEBUG [tomcat-http--6] {} org.apache.cxf.ws.policy.ClientPolicyInFaultInterceptor - faultInterceptors: []
      2018-04-16 09:34:33,682 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Invoking handleMessage on interceptor org.apache.cxf.interceptor.LoggingInInterceptor@f56e35b
      2018-04-16 09:34:33,682 INFO [tomcat-http--6] {} org.apache.cxf.interceptor.LoggingInInterceptor - Inbound Message
      ----------------------------
      ID: 5
      Address: https://server001.myapp.com/v1/AuthorizationService/entitlements/authorizations
      Http-Method: POST
      Content-Type: application/xml
      Headers:

      {Accept=[application/xml], Context-Type=[application/xml], Content-Type=[application/xml], x-security-header-signature=[QliBhrMwTdlczMysN/OEBFDUXHZgvGzl9VvvK4OOaloEtmMVxSbRcNAx1mydZJ4kT0/sFUh/dkZlbtzLRLaPLgPvuSAy7Kve0fnwYMdW4ad86l3KwUbH46nLJi3GCKm0anT+tmb68HXXqLRw4Ph6sy4Lcwgvo5OY+7u36X0dckw=], x-security-msg-version=[1], x-security-host=[SY4-67HSN22], x-security-msg-id=[bacb9976-ac58-4546-9379-1332e2530d00], x-security-app-name=[ebs-non-revenue-gateway:3.2.4-SNAPSHOT-SNAPSHOT], x-security-payload-signature=[MPubxRTbdTzdRUu96hKMyc+uHVUHMxHRQBWXkXcj6jXkbqae0m23IgaF6VanzHYd4HpV4n/WyhqbVnnTBW/Eo+b6GhGbTdtjl0+r9gNoofjCgZMUQkj6Wj3kE3fyfsYAyr5i2Ae2YUYuV46PWbXjWY5H+hN/cJVghZQaQm5Hv+8=], x-security-correlation-id=[cccc4e4e-f7f3-4ba4-9b72-4d32538ecf02], x-security-service-version=[1.0.0], x-security-timestamp=[1523889273497], x-security-security-token=[249d0ce2-73cf-409f-a295-e298c0ba92c2:amcyY2JzdGQ:eGxkdGZzMTA:LmRldi4:3]}

      --------------------------------------
      2018-04-16 09:34:33,682 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Invoking handleMessage on interceptor org.apache.cxf.interceptor.ClientFaultConverter@38b4d45b
      2018-04-16 09:34:33,682 DEBUG [tomcat-http--6] {} org.apache.cxf.phase.PhaseInterceptorChain - Invoking handleMessage on interceptor org.apache.cxf.ws.policy.PolicyVerificationInFaultInterceptor@925feb4
      2018-04-16 09:34:33,684 INFO [tomcat-http--6] {} myapp.client.security.client.penta.SecurityInvocationHandler - Error Code:400 Error Message:java.io.SequenceInputStream@2dd8abaf
      2018-04-16 09:34:33,684 DEBUG [tomcat-http--6] {} myapp.core.service.authorize.ServiceOutboundGatewayImpl - Authorize Service errorjava.io.SequenceInputStream@2dd8abaf
      javax.ws.rs.BadRequestException: HTTP 400 Bad Request
      at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
      at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
      at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

       

       

      NOTE:

      1. **There is no problem with Interceptors being invoked, everything looks good on that part.
      2. Only difference is, in case of success we have code that reads the response body (entity) by checking response code (not  >= 400).
      3. In case of an error response which has response-code >=400, are being treated as faults and the respective interceptors are being invoked correctly. But the issue is earlier version had directly mapping complete response in message.getContents(), but now that's no longer working as this code in CXF classes gets me response payload=java.io.SequenceInputStream@2dd8abaf, which is causing a problem with my response handling, as I was totally dependent on CXF response body in case of these 400 error responses.

        Attachments

        1. CXF3-Objects.JPG
          107 kB
          Muni
        2. CXF2-Objects.JPG
          111 kB
          Muni

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              muni450 Muni
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: