tomcat-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From bugzi...@apache.org
Subject [Bug 58481] New: JAX WS Request fails with "Premature end of file"
Date Mon, 05 Oct 2015 12:13:02 GMT
https://bz.apache.org/bugzilla/show_bug.cgi?id=58481

            Bug ID: 58481
           Summary: JAX WS Request fails with "Premature end of file"
           Product: Tomcat Connectors
           Version: 1.2.41
          Hardware: PC
                OS: Linux
            Status: NEW
          Severity: normal
          Priority: P2
         Component: mod_jk
          Assignee: dev@tomcat.apache.org
          Reporter: cir@silbergrau.com

Invoking jax-ws Webservice with sop-ui, in quick succession.
First request succeeds, second fails, see dump for details.
Error also happens with mod_proxy.

Using mod_proxy client gets SOAP Fault, using mod_jk third request (retry) is
triggered an succeeds again.....

Tested with:
Tomcat: 8.0.24/26/27
JDK: 1.8.0_60, 1.8.0_51
Apache/2.4.10 (Fedora) and Apache/2.2.15 (Unix)

using Servlet Support for JAX-WS RI:
<dependency>
<groupId>com.sun.xml.ws</groupId>
 <artifactId>servlet</artifactId>
 <version>2.2.10</version>
</dependency>


Tomcat startup log:
Oct 05, 2015 1:05:17 PM org.apache.tomcat.util.digester.SetPropertiesRule begin
WARNING: [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting
property 'source' to 'org.eclipse.jst.jee.server:GPDB_services' did not find a
matching property.
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version:        Apache Tomcat/8.0.26
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built:          Aug 18 2015 11:38:37 UTC
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number:         8.0.26.0
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name:               Linux
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version:            3.17.7-200.fc20.x86_64
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture:          amd64
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Java Home:             /usr/java/jdk1.8.0_60/jre
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version:           1.8.0_60-b27
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor:            Oracle Corporation
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE:        
/home/cir/space/.metadata/.plugins/org.eclipse.wst.server.core/tmp2
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME:         /home/cir/apache-tomcat-8.0.26
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument:
-agentlib:jdwp=transport=dt_socket,suspend=y,address=localhost:46230
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument:
-Dcatalina.base=/home/cir/space/.metadata/.plugins/org.eclipse.wst.server.core/tmp2
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/home/cir/apache-tomcat-8.0.26
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument:
-Dwtp.deploy=/home/cir/space/.metadata/.plugins/org.eclipse.wst.server.core/tmp2/wtpwebapps
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument:
-Djava.endorsed.dirs=/home/cir/apache-tomcat-8.0.26/endorsed
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument:
-Djava.security.auth.login.config=/home/cir/keplerSpaces/wks/GPDB_portal/install/auth.conf
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument:
-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xms2g
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xmx4g
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+UseG1GC
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:MaxGCPauseMillis=100
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:G1HeapRegionSize=32M
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:+ParallelRefProcEnabled
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -XX:-ResizePLAB
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument:
-Dcom.sun.xml.ws.transport.http.HttpAdapter.dump=true
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dfile.encoding=UTF-8
Oct 05, 2015 1:05:17 PM org.apache.catalina.core.AprLifecycleListener
lifecycleEvent
INFO: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version
1.5.1.
Oct 05, 2015 1:05:17 PM org.apache.catalina.core.AprLifecycleListener
lifecycleEvent
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false],
random [true].
Oct 05, 2015 1:05:17 PM org.apache.catalina.core.AprLifecycleListener
initializeSSL
INFO: OpenSSL successfully initialized (OpenSSL 1.0.1e 11 Feb 2013)
Oct 05, 2015 1:05:17 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-apr-8080"]
Oct 05, 2015 1:05:17 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-apr-8009"]
Oct 05, 2015 1:05:17 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 699 ms
Oct 05, 2015 1:05:17 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Oct 05, 2015 1:05:17 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/8.0.26

Dump with "Dcom.sun.xml.ws.transport.http.HttpAdapter.dump"
First Request succeeds:

---[HTTP request]---
Accept-Encoding: gzip,deflate
connection: Keep-Alive
content-length: 408
content-type: text/xml;charset=UTF-8
host: localhost
SOAPAction: "http://portal.wkblue.at/ws/getApprenticeshipContracts"
user-agent: Apache-HttpClient/4.1.1 (java 1.5)
<soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"
xmlns:ws="http://portal.wkblue.at/ws">
   <soapenv:Header/>
   <soapenv:Body>
      <ws:getApprenticeshipContractsRequest>
         <economicChamber>5</economicChamber>
         <memberId>107572</memberId>
         <user>1062693667594043394</user>
      </ws:getApprenticeshipContractsRequest>
   </soapenv:Body>
</soapenv:Envelope>--------------------

[2015-10-05 13:11:29][][][.][][2daf4b5d] INFO  Creating new session for key
53|1062693770673258504 ORIGIN: SessionFactory.createSession
[2015-10-05 13:11:29][][][.][][2daf4b5d] INFO  Created new session
Session{id=53|1062693770673258504} (session number 7) ORIGIN:
SessionFactory.createSession
[2015-10-05 13:11:29][][][7.BatchConversation7][][4525624d] INFO  Kammer: 5
Mitglied: 107572 User: 1062693667594043394 requests: getApprenticeshipContracts
ORIGIN: EServiceServicesSOAPImpl$1.getApprenticeshipContracts
[2015-10-05 13:11:29][][][7.BatchConversation7][][4525624d] INFO  Found: 3
contratcs! ORIGIN: EServiceServicesSOAPImpl$1.getApprenticeshipContracts
---[HTTP response 200]---
<?xml version="1.0" ?><S:Envelope
xmlns:S="http://schemas.xmlsoap.org/soap/envelope/"><S:Body><ns2:getApprenticeshipContractsResponse
xmlns:ns2="http://portal.wkblue.at/ws"><apprenticeshipContracts><wkblueID>0</wkblueID><lastSchoolId>0</lastSchoolId><classYear>0</classYear><startOfApprenticeship>2015-09-01+02:00</startOfApprenticeship><apprenticeshipCredits>false</apprenticeshipCredits><schoolCredits>false</schoolCredits><limitedPeriodOfRetention>false</limitedPeriodOfRetention><apprentice><title>Ing.</title><name><firstname>Christoph</firstname><lastname>Irndorfer</lastname></name></apprentice><firstProfession><tradeLicenceId>0</tradeLicenceId><teachingProfessionId>0</teachingProfessionId><professionsCount>0</professionsCount><firstTeachingProfessionModuleId>0</firstTeachingProfessionModuleId><secondTeachingProfessionModuleId>0</secondTeachingProfessionModuleId><alternative>Einzelhandelskaufmann
(0600)</alternative></firstProfession><secondProfession><tradeLicenceId>0</tradeLicenceId><teachingProfessionId>0</teachingProfessionId><professionsCount>0</professionsCount><firstTeachingProfessionModuleId>0</firstTeachingProfessionModuleId><secondTeachingProfessionModuleId>0</secondTeachingProfessionModuleId></secondProfession><instructor><wkblueID>0</wkblueID><number>0</number><title>DI</title><name><firstname>Hans</firstname><lastname>Krankl</lastname></name></instructor><supervisor><wkblueID>0</wkblueID><number>0</number><name><firstname>Martin</firstname><lastname>Perwein</lastname></name></supervisor><status>FINISHED</status><creationDate>2015-06-02T15:27:33.777+02:00</creationDate></apprenticeshipContracts><apprenticeshipContracts><wkblueID>0</wkblueID><lastSchoolId>0</lastSchoolId><classYear>0</classYear><startOfApprenticeship>2015-06-30+02:00</startOfApprenticeship><apprenticeshipCredits>false</apprenticeshipCredits><schoolCredits>false</schoolCredits><limitedPeriodOfRetent
 ion>false</limitedPeriodOfRetention><apprentice><title>Ing.</title><name><firstname>Christoph</firstname><lastname>Irndorfer</lastname></name></apprentice><firstProfession><tradeLicenceId>0</tradeLicenceId><teachingProfessionId>0</teachingProfessionId><professionsCount>0</professionsCount><firstTeachingProfessionModuleId>0</firstTeachingProfessionModuleId><secondTeachingProfessionModuleId>0</secondTeachingProfessionModuleId><alternative>Einzelhandelskaufmann
(0600)</alternative></firstProfession><secondProfession><tradeLicenceId>0</tradeLicenceId><teachingProfessionId>0</teachingProfessionId><professionsCount>0</professionsCount><firstTeachingProfessionModuleId>0</firstTeachingProfessionModuleId><secondTeachingProfessionModuleId>0</secondTeachingProfessionModuleId></secondProfession><instructor><wkblueID>0</wkblueID><number>0</number><title>DI</title><name><firstname>Neuer</firstname><lastname>Ausbilder</lastname></name></instructor><supervisor><wkblueID>0</wkblueID><number>0</number><name><firstname>Martin</firstname><lastname>Perwein</lastname></name></supervisor><status>FINISHED</status><creationDate>2015-06-02T16:40:31.680+02:00</creationDate></apprenticeshipContracts><apprenticeshipContracts><wkblueID>0</wkblueID><lastSchoolId>0</lastSchoolId><classYear>0</classYear><startOfApprenticeship>2015-09-01+02:00</startOfApprenticeship><apprenticeshipCredits>false</apprenticeshipCredits><schoolCredits>false</schoolCredits><limitedPeriodOfRe
 tention>false</limitedPeriodOfRetention><apprentice><name><firstname>Christoph</firstname><lastname>Irndorfer</lastname></name></apprentice><firstProfession><tradeLicenceId>0</tradeLicenceId><teachingProfessionId>0</teachingProfessionId><professionsCount>0</professionsCount><firstTeachingProfessionModuleId>0</firstTeachingProfessionModuleId><secondTeachingProfessionModuleId>0</secondTeachingProfessionModuleId><alternative>Einzelhandelskaufmann
(0600)</alternative></firstProfession><secondProfession><tradeLicenceId>0</tradeLicenceId><teachingProfessionId>0</teachingProfessionId><professionsCount>0</professionsCount><firstTeachingProfessionModuleId>0</firstTeachingProfessionModuleId><secondTeachingProfessionModuleId>0</

Message has been truncated
use com.sun.xml.ws.transport.http.HttpAdapter.dumpTreshold property to increase
the amount of printed part of the message
--------------------

Second Request fails and duplicates Header-Attriburtes:
---[HTTP request]---
Accept-Encoding: gzip,deflate
Accept-Encoding: gzip,deflate
connection: Keep-Alive
connection: Keep-Alive
content-length: 408
content-length: 408
content-type: text/xml;charset=UTF-8
content-type: text/xml;charset=UTF-8
host: localhost
host: localhost
SOAPAction: "http://portal.wkblue.at/ws/getApprenticeshipContracts"
SOAPAction: "http://portal.wkblue.at/ws/getApprenticeshipContracts"
user-agent: Apache-HttpClient/4.1.1 (java 1.5)
user-agent: Apache-HttpClient/4.1.1 (java 1.5)
--------------------

[2015-10-05 13:34:12][][][.][][] ERROR Couldn't create SOAP message due to
exception: XML reader error: javax.xml.stream.XMLStreamException: ParseError at
[row,col]:[1,1]
Message: Premature end of file. ORIGIN: HttpAdapter.invokeAsync
com.sun.xml.ws.protocol.soap.MessageCreationException: Couldn't create SOAP
message due to exception: XML reader error:
javax.xml.stream.XMLStreamException: ParseError at [row,col]:[1,1]
Message: Premature end of file.
    at
com.sun.xml.ws.encoding.SOAPBindingCodec.decode(SOAPBindingCodec.java:319)
    at
com.sun.xml.ws.transport.http.HttpAdapter.decodePacket(HttpAdapter.java:503)
    at
com.sun.xml.ws.transport.http.HttpAdapter.invokeAsync(HttpAdapter.java:713)
    at
com.sun.xml.ws.transport.http.servlet.ServletAdapter.invokeAsync(ServletAdapter.java:212)
    at
com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doGet(WSServletDelegate.java:161)
    at
com.sun.xml.ws.transport.http.servlet.WSServletDelegate.doPost(WSServletDelegate.java:197)
    at
com.sun.xml.ws.transport.http.servlet.WSServlet.doPost(WSServlet.java:81)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:648)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
    at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291)
    at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
    at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
    at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
    at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
    at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
    at
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:616)
    at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
    at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518)
    at
org.apache.coyote.ajp.AbstractAjpProcessor.process(AbstractAjpProcessor.java:844)
    at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:663)
    at
org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2440)
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)
Caused by: com.sun.xml.ws.streaming.XMLStreamReaderException: XML reader error:
javax.xml.stream.XMLStreamException: ParseError at [row,col]:[1,1]
Message: Premature end of file.
    at
com.sun.xml.ws.streaming.XMLStreamReaderUtil.wrapException(XMLStreamReaderUtil.java:326)
    at
com.sun.xml.ws.streaming.XMLStreamReaderUtil.next(XMLStreamReaderUtil.java:99)
    at
com.sun.xml.ws.streaming.XMLStreamReaderUtil.nextContent(XMLStreamReaderUtil.java:169)
    at
com.sun.xml.ws.streaming.XMLStreamReaderUtil.nextElementContent(XMLStreamReaderUtil.java:104)
    at com.sun.xml.ws.encoding.StreamSOAPCodec.decode(StreamSOAPCodec.java:215)
    at
com.oracle.webservices.impl.encoding.StreamDecoderImpl.decode(StreamDecoderImpl.java:64)
    at com.sun.xml.ws.encoding.StreamSOAPCodec.decode(StreamSOAPCodec.java:249)
    at com.sun.xml.ws.encoding.StreamSOAPCodec.decode(StreamSOAPCodec.java:166)
    at
com.sun.xml.ws.encoding.SOAPBindingCodec.decode(SOAPBindingCodec.java:314)
    ... 27 more
Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[1,1]
Message: Premature end of file.
    at
com.sun.org.apache.xerces.internal.impl.XMLStreamReaderImpl.next(XMLStreamReaderImpl.java:601)
    at
com.sun.xml.ws.util.xml.XMLStreamReaderFilter.next(XMLStreamReaderFilter.java:96)
    at
com.sun.xml.ws.streaming.XMLStreamReaderUtil.next(XMLStreamReaderUtil.java:80)
    ... 34 more
---[HTTP response 500]---
<?xml version="1.0" ?><S:Envelope
xmlns:S="http://schemas.xmlsoap.org/soap/envelope/"><S:Body><S:Fault
xmlns:ns4="http://www.w3.org/2003/05/soap-envelope"
xmlns=""><faultcode>S:Client</faultcode><faultstring>Couldn't create
SOAP
message due to exception: XML reader error:
javax.xml.stream.XMLStreamException: ParseError at [row,col]:[1,1]
Message: Premature end of
file.</faultstring></S:Fault></S:Body></S:Envelope>--------------------

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


Mime
View raw message