Uploaded image for project: 'Spring Web Services'
  1. Spring Web Services
  2. SWS-576

sentMessageTracingLogger skips request message headerer content

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 1.5.3, 1.5.8
    • Fix Version/s: 1.5.9
    • Component/s: Core
    • Labels:
      None
    • Environment:
      Widnows XP, Websphere 6.1.0.19, SAAJ 1.3 (sun implementation), MTOM enabled JAXB2 marshaller.

      Description

      In org.springframework.ws.server.MessageDispatcher class sentMessageTracingLogger with trace level does not log the same request message as the one being logged by receivedMessageTracingLogger.
      I've noticed that request message having <SOAP-ENV:Header> with wss4j stuff is properly logged by receivedMessageTracingLogger on trace level:

      Received request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
      <SOAP-ENV:Header>
      <wsse:Security xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd" SOAP-ENV:mustUnderstand="1">
      <wsse:UsernameToken xmlns:wsu="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd" wsu:Id="UsernameToken-21398464">
      <wsse:Username>876543</wsse:Username>
      <wsse:Password Type="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-username-token-profile-1.0#PasswordText">a701050a4e03ef54319c319c9a06a895</wsse:Password>
      </wsse:UsernameToken>
      </wsse:Security>
      </SOAP-ENV:Header>
      <SOAP-ENV:Body>....</SOAP-ENV:Body></SOAP-ENV:Envelope>] 

      Unfortunately sentMessageTracingLogger strips out content of <SOAP-ENV:Header> when logging request message:

      Sent response [------=_Part_18_463346590.1255441172093
      Content-Type: application/xop+xml; type="text/xml"; charset=utf-8
       
      <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
      <SOAP-ENV:Header/>
      <SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>
      ------=_Part_18_463346590.1255441172093--] for request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header>
      </SOAP-ENV:Header><SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>

      It seems that wss4j headers are processed by WSS4j Interceptor and then somehow removed from requestMessage. Actually had no time to dig it further and check if custom headres are also stripped out.
      Anyway i think that sentMessageTracingLogger should log original client request message.
      I am attaching patch version of MessageDispatcher

        Activity

        miluch Jakub Milkiewicz created issue -
        Hide
        arjen.poutsma Arjen Poutsma added a comment -

        Formatting

        Show
        arjen.poutsma Arjen Poutsma added a comment - Formatting
        arjen.poutsma Arjen Poutsma made changes -
        Field Original Value New Value
        Description In org.springframework.ws.server.MessageDispatcher class sentMessageTracingLogger with trace level does not log the same request message as the one being logged by receivedMessageTracingLogger.
        I've noticed that request message having <SOAP-ENV:Header> with wss4j stuff is properly logged by receivedMessageTracingLogger on trace level:

        Received request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header>
        <wsse:Security xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd" SOAP-ENV:mustUnderstand="1"><wsse:UsernameToken xmlns:wsu="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd" wsu:Id="UsernameToken-21398464"><wsse:Username>876543</wsse:Username><wsse:Password Type="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-username-token-profile-1.0#PasswordText">a701050a4e03ef54319c319c9a06a895</wsse:Password></wsse:UsernameToken></wsse:Security></SOAP-ENV:Header><SOAP-ENV:Body>....</SOAP-ENV:Body></SOAP-ENV:Envelope>]

        Unfortunately sentMessageTracingLogger strips out content of <SOAP-ENV:Header> when logging request message:
        Sent response [------=_Part_18_463346590.1255441172093
        Content-Type: application/xop+xml; type="text/xml"; charset=utf-8

        <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header/><SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>
        ------=_Part_18_463346590.1255441172093--] for request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header>
        </SOAP-ENV:Header><SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>

        It seems that wss4j headers are processed by WSS4j Interceptor and then somehow removed from requestMessage. Actually had no time to dig it further and check if custom headres are also stripped out.
        Anyway i think that sentMessageTracingLogger should log original client request message.
        I am attaching patch version of MessageDispatcher
        In org.springframework.ws.server.MessageDispatcher class sentMessageTracingLogger with trace level does not log the same request message as the one being logged by receivedMessageTracingLogger.
        I've noticed that request message having <SOAP-ENV:Header> with wss4j stuff is properly logged by receivedMessageTracingLogger on trace level:

        {noformat}
        Received request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header>
        <wsse:Security xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd" SOAP-ENV:mustUnderstand="1"><wsse:UsernameToken xmlns:wsu="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd" wsu:Id="UsernameToken-21398464"><wsse:Username>876543</wsse:Username><wsse:Password Type="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-username-token-profile-1.0#PasswordText">a701050a4e03ef54319c319c9a06a895</wsse:Password></wsse:UsernameToken></wsse:Security></SOAP-ENV:Header><SOAP-ENV:Body>....</SOAP-ENV:Body></SOAP-ENV:Envelope>]
        {noformat}

        Unfortunately sentMessageTracingLogger strips out content of <SOAP-ENV:Header> when logging request message:
        {noformat}
        Sent response [------=_Part_18_463346590.1255441172093
        Content-Type: application/xop+xml; type="text/xml"; charset=utf-8

        <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header/><SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>
        ------=_Part_18_463346590.1255441172093--] for request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header>
        </SOAP-ENV:Header><SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>
        {noformat}

        It seems that wss4j headers are processed by WSS4j Interceptor and then somehow removed from requestMessage. Actually had no time to dig it further and check if custom headres are also stripped out.
        Anyway i think that sentMessageTracingLogger should log original client request message.
        I am attaching patch version of MessageDispatcher
        arjen.poutsma Arjen Poutsma made changes -
        Description In org.springframework.ws.server.MessageDispatcher class sentMessageTracingLogger with trace level does not log the same request message as the one being logged by receivedMessageTracingLogger.
        I've noticed that request message having <SOAP-ENV:Header> with wss4j stuff is properly logged by receivedMessageTracingLogger on trace level:

        {noformat}
        Received request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header>
        <wsse:Security xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd" SOAP-ENV:mustUnderstand="1"><wsse:UsernameToken xmlns:wsu="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd" wsu:Id="UsernameToken-21398464"><wsse:Username>876543</wsse:Username><wsse:Password Type="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-username-token-profile-1.0#PasswordText">a701050a4e03ef54319c319c9a06a895</wsse:Password></wsse:UsernameToken></wsse:Security></SOAP-ENV:Header><SOAP-ENV:Body>....</SOAP-ENV:Body></SOAP-ENV:Envelope>]
        {noformat}

        Unfortunately sentMessageTracingLogger strips out content of <SOAP-ENV:Header> when logging request message:
        {noformat}
        Sent response [------=_Part_18_463346590.1255441172093
        Content-Type: application/xop+xml; type="text/xml"; charset=utf-8

        <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header/><SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>
        ------=_Part_18_463346590.1255441172093--] for request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header>
        </SOAP-ENV:Header><SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>
        {noformat}

        It seems that wss4j headers are processed by WSS4j Interceptor and then somehow removed from requestMessage. Actually had no time to dig it further and check if custom headres are also stripped out.
        Anyway i think that sentMessageTracingLogger should log original client request message.
        I am attaching patch version of MessageDispatcher
        In org.springframework.ws.server.MessageDispatcher class sentMessageTracingLogger with trace level does not log the same request message as the one being logged by receivedMessageTracingLogger.
        I've noticed that request message having <SOAP-ENV:Header> with wss4j stuff is properly logged by receivedMessageTracingLogger on trace level:

        {noformat}
        Received request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
        <SOAP-ENV:Header>
        <wsse:Security xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd" SOAP-ENV:mustUnderstand="1">
        <wsse:UsernameToken xmlns:wsu="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd" wsu:Id="UsernameToken-21398464">
        <wsse:Username>876543</wsse:Username>
        <wsse:Password Type="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-username-token-profile-1.0#PasswordText">a701050a4e03ef54319c319c9a06a895</wsse:Password>
        </wsse:UsernameToken>
        </wsse:Security>
        </SOAP-ENV:Header>
        <SOAP-ENV:Body>....</SOAP-ENV:Body></SOAP-ENV:Envelope>]
        {noformat}

        Unfortunately sentMessageTracingLogger strips out content of <SOAP-ENV:Header> when logging request message:
        {noformat}
        Sent response [------=_Part_18_463346590.1255441172093
        Content-Type: application/xop+xml; type="text/xml"; charset=utf-8

        <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
        <SOAP-ENV:Header/>
        <SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>
        ------=_Part_18_463346590.1255441172093--] for request [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header>
        </SOAP-ENV:Header><SOAP-ENV:Body>...</SOAP-ENV:Body></SOAP-ENV:Envelope>
        {noformat}

        It seems that wss4j headers are processed by WSS4j Interceptor and then somehow removed from requestMessage. Actually had no time to dig it further and check if custom headres are also stripped out.
        Anyway i think that sentMessageTracingLogger should log original client request message.
        I am attaching patch version of MessageDispatcher
        arjen.poutsma Arjen Poutsma made changes -
        Fix Version/s 1.5.9 [ 11296 ]
        arjen.poutsma Arjen Poutsma made changes -
        Status Open [ 1 ] In Progress [ 3 ]
        arjen.poutsma Arjen Poutsma logged work - 10/Nov/09 9:01 PM
        • Time Spent:
          0.3h
           
          <No comment>
        arjen.poutsma Arjen Poutsma made changes -
        Remaining Estimate 0d [ 0 ]
        Time Spent 0.3h [ 1080 ]
        arjen.poutsma Arjen Poutsma made changes -
        Resolution Fixed [ 1 ]
        Status In Progress [ 3 ] Resolved [ 5 ]
        Hide
        arjen.poutsma Arjen Poutsma added a comment -

        Indeed, the WSS4J interceptors change the request content, getting rid of security headers. This conforms to the SOAP spec, which says that a processing node should remove the headers that belong to it after processing.

        That said, this issue should be fixed now: we keep a reference to the request content as it came in.

        Show
        arjen.poutsma Arjen Poutsma added a comment - Indeed, the WSS4J interceptors change the request content, getting rid of security headers. This conforms to the SOAP spec, which says that a processing node should remove the headers that belong to it after processing. That said, this issue should be fixed now: we keep a reference to the request content as it came in.
        Hide
        arjen.poutsma Arjen Poutsma added a comment - - edited

        @Jakub,

        I think you forgot to attach your patch to this issue. We have some issues with our JIRA installation a few weeks ago, perhaps we lost your patch in the process. But let me know if the solution currently in svn is not working for you. A shame we didn't get to chat at Devoxx.

        Cheers,

        Arjen

        Show
        arjen.poutsma Arjen Poutsma added a comment - - edited @Jakub, I think you forgot to attach your patch to this issue. We have some issues with our JIRA installation a few weeks ago, perhaps we lost your patch in the process. But let me know if the solution currently in svn is not working for you. A shame we didn't get to chat at Devoxx. Cheers, Arjen
        Hide
        miluch Jakub Milkiewicz added a comment -

        I am quite sure i successfully attached patch but it does not matter now since it is nearly identical to yours.
        I believe your code works as expected but I haven't tried it, since I am still using SWS 1.5.5 ( with my original patch applied).
        It is all because of https://jira.springsource.org/browse/SWS-374 and Websphere. Actually i haven't checked myself if newer (above 1.5.5) versions of SWS work on Websphere but according to comments by Sebastien Dubois these do not work. I am planning to check it myself this week.
        Back to devoxx: really ashame we had no time to chat but actually i have not seen you at all in Antwerp! I had a chat with Peter Meijer on Tuesday and have seen him quite regularly till Thursday afternoon at SpringSource booth but I haven't seen you at all during whole conference! During one of launch breaks I have met Tareq and have just asked him a couple of SWS related questions. I hope we will have a chat/beer during next SpringOne/geecon.

        Show
        miluch Jakub Milkiewicz added a comment - I am quite sure i successfully attached patch but it does not matter now since it is nearly identical to yours. I believe your code works as expected but I haven't tried it, since I am still using SWS 1.5.5 ( with my original patch applied). It is all because of https://jira.springsource.org/browse/SWS-374 and Websphere. Actually i haven't checked myself if newer (above 1.5.5) versions of SWS work on Websphere but according to comments by Sebastien Dubois these do not work. I am planning to check it myself this week. Back to devoxx: really ashame we had no time to chat but actually i have not seen you at all in Antwerp! I had a chat with Peter Meijer on Tuesday and have seen him quite regularly till Thursday afternoon at SpringSource booth but I haven't seen you at all during whole conference! During one of launch breaks I have met Tareq and have just asked him a couple of SWS related questions. I hope we will have a chat/beer during next SpringOne/geecon.
        Hide
        arjen.poutsma Arjen Poutsma added a comment -

        Closing old issues

        Show
        arjen.poutsma Arjen Poutsma added a comment - Closing old issues
        arjen.poutsma Arjen Poutsma made changes -
        Status Resolved [ 5 ] Closed [ 6 ]
        Transition Time In Source Status Execution Times Last Executer Last Execution Date
        Open Open In Progress In Progress
        28d 2m 1 Arjen Poutsma 10/Nov/09 8:42 PM
        In Progress In Progress Resolved Resolved
        19m 9s 1 Arjen Poutsma 10/Nov/09 9:02 PM
        Resolved Resolved Closed Closed
        905d 10h 1m 1 Arjen Poutsma 04/May/12 7:03 AM

          People

          • Assignee:
            arjen.poutsma Arjen Poutsma
            Reporter:
            miluch Jakub Milkiewicz
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Time Tracking

              Estimated:
              Original Estimate - Not Specified
              Not Specified
              Remaining:
              Remaining Estimate - 0d
              0d
              Logged:
              Time Spent - 0.3h
              0.3h