org.xml.sax.SAXParseException: The root element is required in a well-formed document

[jgoober]

And here is the output of the web service client call that works after patching the org.springframework.ws.transport.http.HttpUrlConne ction class:

[2007:12:03:11:19:05:250] [main] [INFO] [org.springframework.ws.soap.saaj.SaajSoapMessageFactory] [afterPropertiesSet] [SaajSoapMessageFactory.java] [111] [Creating SAAJ 1.2 MessageFactory]
[2007:12:03:11:19:05:265] [main] [DEBUG] [org.springframework.ws.soap.saaj.SaajSoapMessageFactory] [afterPropertiesSet] [SaajSoapMessageFactory.java] [134] [Using MessageFactory class [org.apache.axis.soap.MessageFactoryImpl]]
[2007:12:03:11:19:05:296] [main] [INFO] [org.springframework.oxm.jaxb.Jaxb1Marshaller] [createJaxbContext] [Jaxb1Marshaller.java] [78] [Creating JAXBContext with context path [com.aa.selfservice.cne.fsn.subscription.ws.schema]]
[2007:12:03:11:19:05:359] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [marshalSendAndReceive] [WebServiceTemplate.java] [261] [Entering marshalSendAndReceive(x, x, x)]
[2007:12:03:11:19:05:359] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [marshalSendAndReceive] [WebServiceTemplate.java] [270] [Calling sendAndReceive(String, WebServiceMessageCallback, WebServiceMessageExtractor)]
[2007:12:03:11:19:05:359] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [sendAndReceive] [WebServiceTemplate.java] [424] [Entering sendAndReceive(String, WebServiceMessageCallback, WebServiceMessageExtractor)]
[2007:12:03:11:19:05:359] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [sendAndReceive] [WebServiceTemplate.java] [433] [Calling createConnection(uri)]
[2007:12:03:11:19:05:359] [main] [DEBUG] [org.springframework.ws.client.support.WebServiceAccessor] [createConnection] [WebServiceAccessor.java] [106] [Opening connection to [http://127.0.0.1:8080/cne-ws/fsnsubs/services] using [org.springframework.ws.transport.http.HttpUrlConnectionMessageSender@9505f]]
[2007:12:03:11:19:05:375] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate$1] [doWithMessage] [WebServiceTemplate.java] [277] [Entering doWithMessage(WebServiceMessage request)]
[2007:12:03:11:19:05:453] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate$1] [doWithMessage] [WebServiceTemplate.java] [289] [The requestCallback WAS null]
[2007:12:03:11:19:05:515] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [sendRequest] [WebServiceTemplate.java] [595] [Sent request [<soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
 <soapenv:Body>
  <ns1:CreateFsnAddOnRequest xmlns="http://www.aa.com/cne/fsn/subscriptions/schemas" xmlns:ns1="http://www.aa.com/cne/fsn/subscriptions/schemas">
   <ns1:requestHeader>
    <ns1:eventType>TestEvent01Type</ns1:eventType>
    <ns1:productType>fsn</ns1:productType>
   </ns1:requestHeader>
   <ns1:aadvantageMember>123456</ns1:aadvantageMember>
   <ns1:flight>
    <ns1:pnrLocator>DQASWED</ns1:pnrLocator>
    <ns1:departure>
     <ns1:airportCode>DFW</ns1:airportCode>
     <ns1:flightDateTime>2007-12-03T11:19:05.359-06:00</ns1:flightDateTime>
    </ns1:departure>
    <ns1:arrival>
     <ns1:airportCode>MIA</ns1:airportCode>
    </ns1:arrival>
   </ns1:flight>
   <ns1:preferences>
    <ns1:contact>
     <ns1:id>442</ns1:id>
     <ns1:name>My Cell</ns1:name>
     <ns1:address>2145447456</ns1:address>
     <ns1:protocol>V</ns1:protocol>
     <ns1:contactType>P</ns1:contactType>
    </ns1:contact>
    <ns1:settings>
     <ns1:departureStatus>true</ns1:departureStatus>
     <ns1:arrivalStatus>true</ns1:arrivalStatus>
     <ns1:connectionStatus>true</ns1:connectionStatus>
     <ns1:gateStatus>true</ns1:gateStatus>
     <ns1:notificationInterval>120</ns1:notificationInterval>
    </ns1:settings>
   </ns1:preferences>
  </ns1:CreateFsnAddOnRequest>
 </soapenv:Body>
</soapenv:Envelope>]]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [sendAndReceive] [WebServiceTemplate.java] [447] [Calling connection.receive(MessageFactory)]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractWebServiceConnection] [receive] [AbstractWebServiceConnection.java] [51] [Entering receive(WebServiceMessageFactory)]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractWebServiceConnection] [receive] [AbstractWebServiceConnection.java] [54] [Calling onReceiveBeforeRead()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractWebServiceConnection] [receive] [AbstractWebServiceConnection.java] [58] [Calling createTransportInputStream()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractSenderConnection] [createTransportInputStream] [AbstractSenderConnection.java] [49] [Entering createTransportInputStream()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.http.AbstractHttpSenderConnection] [hasResponse] [AbstractHttpSenderConnection.java] [63] [Entering hasResponse()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.http.AbstractHttpSenderConnection] [hasResponse] [AbstractHttpSenderConnection.java] [73] [Response content length was 495]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractSenderConnection] [createTransportInputStream] [AbstractSenderConnection.java] [54] [The call to hasResponse() returned true]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractSenderConnection] [createTransportInputStream] [AbstractSenderConnection.java] [58] [The responseInputStream was null, creating a new ResponseTransportInputStream]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractWebServiceConnection] [receive] [AbstractWebServiceConnection.java] [71] [Calling createWebServiceMessage(TransportInputStream)]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractWebServiceConnection] [receive] [AbstractWebServiceConnection.java] [77] [Calling TransportInputStream.close()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.TransportInputStream] [close] [TransportInputStream.java] [62] [Entering close()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.TransportInputStream] [getInputStream] [TransportInputStream.java] [46] [Entering getInputStream()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.TransportInputStream] [getInputStream] [TransportInputStream.java] [51] [The inputStream WAS null]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.AbstractSenderConnection$ResponseTransportInputStream] [createInputStream] [AbstractSenderConnection.java] [118] [Calling getResponseInputStream()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.http.AbstractHttpSenderConnection] [getResponseInputStream] [AbstractHttpSenderConnection.java] [91] [Entering getResponseInputStream()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.http.AbstractHttpSenderConnection] [getResponseInputStream] [AbstractHttpSenderConnection.java] [101] [The responseBuffer WAS null, calling getRawResponseInputStream()]
[2007:12:03:11:19:05:546] [main] [DEBUG] [org.springframework.ws.transport.http.HttpUrlConnection] [getRawResponseInputStream] [HttpUrlConnection.java] [135] [Entering getRawResponseInputStream()]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.transport.http.HttpUrlConnection] [getRawResponseInputStream] [HttpUrlConnection.java] [147] [Returning an InputStream]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.transport.AbstractWebServiceConnection] [receive] [AbstractWebServiceConnection.java] [82] [Calling onReceiveAfterRead(WebServiceMessage)]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [sendAndReceive] [WebServiceTemplate.java] [453] [Calling hasFault(connection, response)]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.transport.http.AbstractHttpSenderConnection] [hasFault] [AbstractHttpSenderConnection.java] [136] [Entering hasFault()]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.transport.TransportInputStream] [read] [TransportInputStream.java] [112] [Entering getInputStream()]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.transport.TransportInputStream] [getInputStream] [TransportInputStream.java] [46] [Entering getInputStream()]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.transport.TransportInputStream] [read] [TransportInputStream.java] [112] [Entering getInputStream()]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.transport.TransportInputStream] [getInputStream] [TransportInputStream.java] [46] [Entering getInputStream()]

SEE NEXT POST FOR THE REST....

[jgoober]

[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [logResponse] [WebServiceTemplate.java] [609] [Received response [<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header/><SOAP-ENV:Body><ns2:CreateFsnAddOnResponse xmlns:ns2="http://www.aa.com/cne/fsn/subscriptions/schemas"><ns2:id>4587365383</ns2:id><ns2:responseHeader><ns2:responseCode>300000</ns2:responseCode><ns2:responseType>Cool Beans Wow!</ns2:responseType><ns2:responseMessage>This is the shizzle !!!!!</ns2:responseMessage></ns2:responseHeader></ns2:CreateFsnAddOnResponse></SOAP-ENV:Body></SOAP-ENV:Envelope>] for request [<soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
 <soapenv:Body>
  <ns1:CreateFsnAddOnRequest xmlns="http://www.aa.com/cne/fsn/subscriptions/schemas" xmlns:ns1="http://www.aa.com/cne/fsn/subscriptions/schemas">
   <ns1:requestHeader>
    <ns1:eventType>TestEvent01Type</ns1:eventType>
    <ns1:productType>fsn</ns1:productType>
   </ns1:requestHeader>
   <ns1:aadvantageMember>123456</ns1:aadvantageMember>
   <ns1:flight>
    <ns1:pnrLocator>DQASWED</ns1:pnrLocator>
    <ns1:departure>
     <ns1:airportCode>DFW</ns1:airportCode>
     <ns1:flightDateTime>2007-12-03T11:19:05.359-06:00</ns1:flightDateTime>
    </ns1:departure>
    <ns1:arrival>
     <ns1:airportCode>MIA</ns1:airportCode>
    </ns1:arrival>
   </ns1:flight>
   <ns1:preferences>
    <ns1:contact>
     <ns1:id>442</ns1:id>
     <ns1:name>My Cell</ns1:name>
     <ns1:address>2145447456</ns1:address>
     <ns1:protocol>V</ns1:protocol>
     <ns1:contactType>P</ns1:contactType>
    </ns1:contact>
    <ns1:settings>
     <ns1:departureStatus>true</ns1:departureStatus>
     <ns1:arrivalStatus>true</ns1:arrivalStatus>
     <ns1:connectionStatus>true</ns1:connectionStatus>
     <ns1:gateStatus>true</ns1:gateStatus>
     <ns1:notificationInterval>120</ns1:notificationInterval>
    </ns1:settings>
   </ns1:preferences>
  </ns1:CreateFsnAddOnRequest>
 </soapenv:Body>
</soapenv:Envelope>]]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [sendAndReceive] [WebServiceTemplate.java] [462] [Calling responseExtractor.extractData(response) to return the result]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate$2] [extractData] [WebServiceTemplate.java] [298] [Entering extractData(WebServiceMessage response)]
[2007:12:03:11:19:05:562] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate$2] [extractData] [WebServiceTemplate.java] [301] [Calling MarshallingUtils.unmarshal(getUnmarshaller(), response) to get the response]
[2007:12:03:11:19:05:625] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [sendAndReceive] [WebServiceTemplate.java] [488] [Calling connection.close()]
[2007:12:03:11:19:05:625] [main] [DEBUG] [org.springframework.ws.transport.http.HttpUrlConnection] [close] [HttpUrlConnection.java] [66] [Entering close()]

SEE NEXT POST FOR THE REST...

[jgoober]

You can see from the output of the failing call that the InputStream for the response was not returning anything since it was already closed as noted by the empty brackets "[Received response [] for request ["

[2007:12:03:10:53:35:296] [main] [DEBUG] [org.springframework.ws.client.core.WebServiceTemplate] [logResponse] [WebServiceTemplate.java] [609] [Received response [] for request [<soapenv:Envelope xmlns:soapenv=..........blah, blah, blah>

The snippets of code below denote the changes that I made to the org.springframework.ws.transport.http.HttpUrlConne ction class to correct the issue. As far as I could tell, the org.springframework.ws.transport.http.HttpUrlConne ction.close() method is called after every request / response invocation so it looked safe to store off the contents of the InputStream into a ByteArrayInputStream.

public class HttpUrlConnection extends AbstractHttpSenderConnection {

   private final HttpURLConnection connection;
   private InputStream connStream;         // ADDED THIS LINE
   
   ................
   
    public void close() {
        connection.disconnect();
        connStream = null;          // ADDED THIS LINE
    }
   
   ................
   
    protected InputStream getRawResponseInputStream() throws IOException {

      if (connection.getResponseCode() / 100 != 2) {
            return connection.getErrorStream();
        }
        else {

           if (connStream == null) {        // ADDED THIS LINE
            connStream = new ByteArrayInputStream(FileCopyUtils.copyToByteArray(connection.getInputStream()));    // ADDED THIS LINE
           }                                         // ADDED THIS LINE
          return connStream;              // ADDED THIS LINE
         
         //return connection.getInputStream();  // COMMENTED THIS OUT
         
        }
    }

I neglected to apply the fix for the call "connection.getErrorStream()" within the "getRawResponseInputStream()" method but I would imagine that it should be done the same way as "connection.getInputStream()".

Please let me know if this fix looks appropriate and if someone can apply this in the next revision.

jgoober

[Arjen Poutsma]

I have created SWS-245: http://opensource.atlassian.com/proj...browse/SWS-245. In the future, could you please use JIRA to log issues like these? That saves us both a lot of work, because you can simply attach one log file there, rather than creating four forum messages. Thanks.

I will try and take a look at this issue for the 1.5 M1 release (due next week), but I am not sure it will be fixed in that time frame (with the Spring Experience coming up). It will definitely be fixed in 1.0.3, to be released around the 21st of December.

The downside to your suggested fix to HttpUrlConnection is that it copies the entire response message stream in memory. If you use a streaming SoapMessage implementation (such as Axiom), this might not be suitable. I will investigate.

Thanks again for writing such a detailed report.

[Arjen Poutsma]

Working on this now.

[Arjen Poutsma]

This is now fixed in SVN. The exceptions you got were due to the response inputstream being closed too soon. Now the stream is kept open for as long as the WebServiceConnection is open, i.e. long enough for the extractor to get the data out.