You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by Bill Barker <bi...@apache.org> on 2014/03/12 15:44:31 UTC

[GUMP@vmgump]: Project tomcat-trunk-test-nio2 (in module tomcat-trunk) failed

To whom it may engage...
        
This is an automated request, but not an unsolicited one. For 
more information please visit http://gump.apache.org/nagged.html, 
and/or contact the folk at general@gump.apache.org.

Project tomcat-trunk-test-nio2 has an issue affecting its community integration.
This issue affects 1 projects.
The current state of this project is 'Failed', with reason 'Build Failed'.
For reference only, the following projects are affected by this:
    - tomcat-trunk-test-nio2 :  Tomcat 8.x, a web server implementing the Java Servlet 3.1,
...


Full details are available at:
    http://vmgump.apache.org/gump/public/tomcat-trunk/tomcat-trunk-test-nio2/index.html

That said, some information snippets are provided here.

The following annotations (debug/informational/warning/error messages) were provided:
 -DEBUG- Dependency on commons-daemon exists, no need to add for property commons-daemon.native.src.tgz.
 -DEBUG- Dependency on commons-daemon exists, no need to add for property tomcat-native.tar.gz.
 -DEBUG- Dependency on tomcat-trunk exists, no need to add for property tomcat-dbcp.home.
 -INFO- Failed with reason build failed
 -INFO- Project Reports in: /srv/gump/public/workspace/tomcat-trunk/output/build/logs



The following work was performed:
http://vmgump.apache.org/gump/public/tomcat-trunk/tomcat-trunk-test-nio2/gump_work/build_tomcat-trunk_tomcat-trunk-test-nio2.html
Work Name: build_tomcat-trunk_tomcat-trunk-test-nio2 (Type: Build)
Work ended in a state of : Failed
Elapsed: 28 mins 42 secs
Command Line: /usr/lib/jvm/java-7-oracle/bin/java -Djava.awt.headless=true -Dbuild.sysclasspath=only org.apache.tools.ant.Main -Dgump.merge=/srv/gump/public/gump/work/merge.xml -Djunit.jar=/srv/gump/public/workspace/junit/target/junit-4.12-SNAPSHOT.jar -Dobjenesis.jar=/srv/gump/public/workspace/objenesis/main/target/objenesis-2.2-SNAPSHOT.jar -Dtomcat-native.tar.gz=/srv/gump/public/workspace/apache-commons/daemon/dist/bin/commons-daemon-20140312-native-src.tar.gz -Dexamples.sources.skip=true -Dtomcat-dbcp.home=/srv/gump/public/workspace/tomcat-trunk/tomcat-deps -Djdt.jar=/srv/gump/packages/eclipse/plugins/org.eclipse.jdt.core_3.4.2/jdtcore.jar -Dcommons-daemon.jar=/srv/gump/public/workspace/apache-commons/daemon/dist/commons-daemon-20140312.jar -Dcommons-daemon.native.src.tgz=/srv/gump/public/workspace/apache-commons/daemon/dist/bin/commons-daemon-20140312-native-src.tar.gz -Dexecute.test.nio=false -Dtest.accesslog=true -Dcommons-pool.home=/srv/gump/public/workspace/apache-co
 mmons/pool -Dcommons-dbcp.home=/srv/gump/public/workspace/apache-commons/dbcp -Dexecute.test.nio2=true -Dexecute.test.bio=false -Deasymock.jar=/srv/gump/public/workspace/easymock/easymock/target/easymock-3.3-SNAPSHOT.jar -Dhamcrest.jar=/srv/gump/public/workspace/hamcrest/hamcrest-java/build/hamcrest-core-20140312.jar -Dcglib.jar=/srv/gump/packages/cglib/cglib-nodep-2.2.jar test 
[Working Directory: /srv/gump/public/workspace/tomcat-trunk]
CLASSPATH: /usr/lib/jvm/java-7-oracle/lib/tools.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/webapps/examples/WEB-INF/classes:/srv/gump/public/workspace/tomcat-trunk/output/testclasses:/srv/gump/public/workspace/ant/dist/lib/ant.jar:/srv/gump/public/workspace/ant/dist/lib/ant-launcher.jar:/srv/gump/public/workspace/ant/dist/lib/ant-jmf.jar:/srv/gump/public/workspace/ant/dist/lib/ant-junit.jar:/srv/gump/public/workspace/ant/dist/lib/ant-junit4.jar:/srv/gump/public/workspace/ant/dist/lib/ant-swing.jar:/srv/gump/public/workspace/ant/dist/lib/ant-apache-resolver.jar:/srv/gump/public/workspace/ant/dist/lib/ant-apache-xalan2.jar:/srv/gump/public/workspace/xml-commons/java/build/resolver.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/bin/bootstrap.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/bin/tomcat-juli.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/annotations-api.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/servle
 t-api.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/jsp-api.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/el-api.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/websocket-api.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/catalina.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/catalina-ant.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/catalina-storeconfig.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-coyote.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/jasper.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/jasper-el.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/catalina-tribes.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/catalina-ha.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-api.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-jni.jar:/srv/gump/public/workspace/tomcat
 -trunk/output/build/lib/tomcat-spdy.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-util.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-util-scan.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-websocket.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-i18n-es.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-i18n-fr.jar:/srv/gump/public/workspace/tomcat-trunk/output/build/lib/tomcat-i18n-ja.jar:/srv/gump/packages/javamail-1.4/mail.jar:/srv/gump/packages/javamail-1.4/lib/mailapi.jar:/srv/gump/packages/jaf-1.1ea/activation.jar:/srv/gump/packages/eclipse/plugins/org.eclipse.jdt.core_3.4.2/jdtcore.jar:/srv/gump/public/workspace/apache-commons/daemon/dist/commons-daemon-20140312.jar:/srv/gump/public/workspace/junit/target/junit-4.12-SNAPSHOT.jar:/srv/gump/public/workspace/hamcrest/hamcrest-java/build/hamcrest-core-20140312.jar:/srv/gump/packages/cglib/cglib-nodep-2.2.jar:/srv/gump/p
 ublic/workspace/objenesis/main/target/objenesis-2.2-SNAPSHOT.jar:/srv/gump/public/workspace/easymock/easymock/target/easymock-3.3-SNAPSHOT.jar
---------------------------------------------
    [junit] 12-Mar-2014 14:44:23.851 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio2-127.0.0.1-auto-1-53728"]
    [junit] 12-Mar-2014 14:44:23.852 WARNING [main] org.apache.tomcat.util.net.Nio2Endpoint.startInternal The NIO2 connector is currently EXPERIMENTAL and should not be used in production
    [junit] 12-Mar-2014 14:44:24.221 SEVERE [http-nio2-127.0.0.1-auto-1-exec-6] org.apache.tomcat.websocket.pojo.PojoEndpointBase.onError No error handling configured for [org.apache.tomcat.websocket.pojo.TestPojoMethodMapping$Server] and the following error occurred
    [junit]  java.nio.channels.ClosedChannelException
    [junit] 	at org.apache.coyote.http11.upgrade.Nio2ServletInputStream$1.completed(Nio2ServletInputStream.java:49)
    [junit] 	at org.apache.coyote.http11.upgrade.Nio2ServletInputStream$1.completed(Nio2ServletInputStream.java:44)
    [junit] 	at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
    [junit] 	at sun.nio.ch.Invoker$2.run(Invoker.java:206)
    [junit] 	at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
    [junit] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    [junit] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    [junit] 	at java.lang.Thread.run(Thread.java:724)
    [junit] 
    [junit] 12-Mar-2014 14:44:24.320 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio2-127.0.0.1-auto-1-53728"]
    [junit] 12-Mar-2014 14:44:24.324 INFO [main] org.apache.catalina.core.StandardService.stopInternal Stopping service Tomcat
    [junit] 12-Mar-2014 14:44:24.354 INFO [main] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio2-127.0.0.1-auto-1-53728"]
    [junit] 12-Mar-2014 14:44:24.354 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio2-127.0.0.1-auto-1-53728"]
    [junit] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.189 sec
    [junit] Running org.apache.tomcat.websocket.server.TestUriTemplate
    [junit] Tests run: 20, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.051 sec
    [junit] Running org.apache.tomcat.websocket.server.TestWsServerContainer
    [junit] 12-Mar-2014 14:44:26.740 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio2-127.0.0.1-auto-1"]
    [junit] 12-Mar-2014 14:44:26.810 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service Tomcat
    [junit] 12-Mar-2014 14:44:26.811 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.0.4-dev
    [junit] 12-Mar-2014 14:44:27.269 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio2-127.0.0.1-auto-1-55576"]
    [junit] 12-Mar-2014 14:44:27.270 WARNING [main] org.apache.tomcat.util.net.Nio2Endpoint.startInternal The NIO2 connector is currently EXPERIMENTAL and should not be used in production
    [junit] 12-Mar-2014 14:44:27.280 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio2-127.0.0.1-auto-1-55576"]
    [junit] 12-Mar-2014 14:44:27.284 INFO [main] org.apache.catalina.core.StandardService.stopInternal Stopping service Tomcat
    [junit] 12-Mar-2014 14:44:27.308 INFO [main] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio2-127.0.0.1-auto-1-55576"]
    [junit] 12-Mar-2014 14:44:27.309 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio2-127.0.0.1-auto-1-55576"]
    [junit] 12-Mar-2014 14:44:27.330 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio2-127.0.0.1-auto-2"]
    [junit] 12-Mar-2014 14:44:27.335 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio2-127.0.0.1-auto-3"]
    [junit] 12-Mar-2014 14:44:27.339 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio2-127.0.0.1-auto-4"]
    [junit] 12-Mar-2014 14:44:27.359 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio2-127.0.0.1-auto-5"]
    [junit] Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.686 sec
    [junit] 12-Mar-2014 14:44:27.361 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio2-127.0.0.1-auto-6"]
    [junit] 12-Mar-2014 14:44:27.363 INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio2-127.0.0.1-auto-7"]

test-apr-exists:

test-apr:

cobertura-report:

test:

BUILD FAILED
/srv/gump/public/workspace/tomcat-trunk/build.xml:1322: Some tests completed with a Failure. See /srv/gump/public/workspace/tomcat-trunk/output/build/logs for details, search for "FAILED".

Total time: 28 minutes 42 seconds
---------------------------------------------

To subscribe to this information via syndicated feeds:
- RSS: http://vmgump.apache.org/gump/public/tomcat-trunk/tomcat-trunk-test-nio2/rss.xml
- Atom: http://vmgump.apache.org/gump/public/tomcat-trunk/tomcat-trunk-test-nio2/atom.xml

============================== Gump Tracking Only ===
Produced by Apache Gump(TM) version 2.3.
Gump Run 20140312120004, vmgump.apache.org:vmgump:20140312120004
Gump E-mail Identifier (unique within run) #1.

--
Apache Gump
http://gump.apache.org/ [Instance: vmgump]

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


Re: [GUMP@vmgump]: Project tomcat-trunk-test-nio2 (in module tomcat-trunk) failed

Posted by Rémy Maucherat <re...@apache.org>.
2014-03-12 15:44 GMT+01:00 Bill Barker <bi...@apache.org>:

> Full details are available at:
>
> http://vmgump.apache.org/gump/public/tomcat-trunk/tomcat-trunk-test-nio2/index.html
>

So, after debugging it, I can confirm there's an issue with the test
TestWebSocketFrameClient.testConnectToServerEndpointSSL

It does seem to be caused by a characteristic of NIO2, where the data has
to be encrypted inline (unlike the NIO1 connector). I don't see any
reasonable workaround for this. The test uses a lot of resources (2GB+ of
RAM for me, plus significant CPU), so this processing time could spike.
This then seems to cause a deadlock in the websockets code, which I have
been able to reproduce 100% of the time by adding a Thread.sleep(20) at the
beginning of Nio(2)ServletOutputStream.doWrite (for both NIO and NIO2
connectors, the behavior then becomes identical).

So this can apparently could only affect heavily loaded servers using SSL.
The deadlock is later broken up by the FutureSendHandler timeout.

Although this failure only occurs with the NIO2 connector, I don't consider
its behavior to be incorrect, as non blocking is not supposed to block on
any IO operation, but this doesn't mean all calls need to have zero
processing time.

I'll try to investigate more this likely deadlock sometime later if Mark
doesn't have any ideas about it.

Rémy