Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 313205

Summary:	Unable to run tests on /test/test-sessions/test-jdbc-sessions
Product:	[RT] Jetty	Reporter:	Joakim Erdfelt <joakim.erdfelt>
Component:	build	Assignee:	Joakim Erdfelt <joakim.erdfelt>
Status:	RESOLVED FIXED	QA Contact:
Severity:	normal
Priority:	P3	CC:	jetty-inbox
Version:	7.1.0
Target Milestone:	7.0.2.RC0
Hardware:	PC
OS:	Linux
Whiteboard:

Description Joakim Erdfelt

2010-05-17 13:49:43 EDT

Hundreds of exceptions on the console log with the following stack trace.

2010-05-17 10:48:24.667:WARN::Problem selecting expired sessions
java.sql.SQLException: An SQL data change is not permitted for a read-only connection, user or database.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
	at org.eclipse.jetty.server.session.JDBCSessionIdManager.scavenge(JDBCSessionIdManager.java:681)
	at org.eclipse.jetty.server.session.JDBCSessionIdManager.access$000(JDBCSessionIdManager.java:53)
	at org.eclipse.jetty.server.session.JDBCSessionIdManager$1.run(JDBCSessionIdManager.java:236)
	at java.util.TimerThread.mainLoop(Timer.java:512)
	at java.util.TimerThread.run(Timer.java:462)

Followed by 5 test failures ...

Failed tests: 
  testImmortalSession(org.eclipse.jetty.server.session.ImmortalSessionTest)
  testInvalidation(org.eclipse.jetty.server.session.InvalidationSessionTest)
  testLastAccessTime(org.eclipse.jetty.server.session.LastAccessTimeTest)
  testLocalSessionsScavenging(org.eclipse.jetty.server.session.LocalSessionScavengingTest)
  testSessionMigration(org.eclipse.jetty.server.session.SessionMigrationTest)

-------------------------------------------------------------------------------
Test set: TestSuite
-------------------------------------------------------------------------------
Tests run: 11, Failures: 5, Errors: 0, Skipped: 0, Time elapsed: 24.764 sec <<< FAILURE!
testImmortalSession(org.eclipse.jetty.server.session.ImmortalSessionTest)  Time elapsed: 5.139 sec  <<< FAILURE!
java.lang.AssertionError
	at org.eclipse.jetty.server.session.AbstractImmortalSessionTest.testImmortalSession(AbstractImmortalSessionTest.java:86)
	at org.eclipse.jetty.server.session.ImmortalSessionTest.testImmortalSession(ImmortalSessionTest.java:36)

testInvalidation(org.eclipse.jetty.server.session.InvalidationSessionTest)  Time elapsed: 0.202 sec  <<< FAILURE!
java.lang.AssertionError
	at org.eclipse.jetty.server.session.AbstractInvalidationSessionTest.testInvalidation(AbstractInvalidationSessionTest.java:90)
	at org.eclipse.jetty.server.session.InvalidationSessionTest.testInvalidation(InvalidationSessionTest.java:49)

testLastAccessTime(org.eclipse.jetty.server.session.LastAccessTimeTest)  Time elapsed: 0.195 sec  <<< FAILURE!
java.lang.AssertionError
	at org.eclipse.jetty.server.session.AbstractLastAccessTimeTest.testLastAccessTime(AbstractLastAccessTimeTest.java:91)
	at org.eclipse.jetty.server.session.LastAccessTimeTest.testLastAccessTime(LastAccessTimeTest.java:34)

testLocalSessionsScavenging(org.eclipse.jetty.server.session.LocalSessionScavengingTest)  Time elapsed: 0.212 sec  <<< FAILURE!
java.lang.AssertionError
	at org.eclipse.jetty.server.session.AbstractLocalSessionScavengingTest.testLocalSessionsScavenging(AbstractLocalSessionScavengingTest.java:102)
	at org.eclipse.jetty.server.session.LocalSessionScavengingTest.testLocalSessionsScavenging(LocalSessionScavengingTest.java:50)

testSessionMigration(org.eclipse.jetty.server.session.SessionMigrationTest)  Time elapsed: 0.193 sec  <<< FAILURE!
java.lang.AssertionError
	at org.eclipse.jetty.server.session.AbstractSessionMigrationTest.testSessionMigration(AbstractSessionMigrationTest.java:86)
	at org.eclipse.jetty.server.session.SessionMigrationTest.testSessionMigration(SessionMigrationTest.java:33)

Comment 1 Joakim Erdfelt

2010-05-24 17:02:46 EDT

Just confirming that these failures still occur, despite the ulimit bump to 20,000 open files.

Comment 2 Joakim Erdfelt

2010-05-24 17:16:49 EDT

More stack traces (and an NPE) seen in console output ...
Note: ulimit on file descriptors is at 20,000 during this build run.




2010-05-24 14:14:15.027:WARN::Problem persisting changed session data id=1274735654902t8e7ab40d19h1c5jtr0mltufc
java.sql.SQLException: An SQL data change is not permitted for a read-only connection, user or database.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
	at org.eclipse.jetty.server.session.JDBCSessionManager.updateSession(JDBCSessionManager.java:955)
	at org.eclipse.jetty.server.session.JDBCSessionManager$Session.complete(JDBCSessionManager.java:341)
	at org.eclipse.jetty.server.session.AbstractSessionManager.complete(AbstractSessionManager.java:144)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:199)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:860)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:245)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:113)
	at org.eclipse.jetty.server.Server.handle(Server.java:335)
	at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:588)
	at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1029)
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:549)
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:211)
	at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:418)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:489)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:436)
	at java.lang.Thread.run(Thread.java:619)
java.lang.NullPointerException
	at org.eclipse.jetty.server.session.WebAppObjectInSessionServlet.doGet(WebAppObjectInSessionServlet.java:52)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:527)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:423)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:493)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:924)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:358)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:860)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:245)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:113)
	at org.eclipse.jetty.server.Server.handle(Server.java:335)
	at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:588)
	at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1029)
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:549)
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:211)
	at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:418)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:489)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:436)
	at java.lang.Thread.run(Thread.java:619)
2010-05-24 14:14:15.144:WARN::Problem selecting expired sessions
java.sql.SQLException: An SQL data change is not permitted for a read-only connection, user or database.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
	at org.eclipse.jetty.server.session.JDBCSessionIdManager.scavenge(JDBCSessionIdManager.java:681)
	at org.eclipse.jetty.server.session.JDBCSessionIdManager.access$000(JDBCSessionIdManager.java:53)
	at org.eclipse.jetty.server.session.JDBCSessionIdManager$1.run(JDBCSessionIdManager.java:236)
	at java.util.TimerThread.mainLoop(Timer.java:512)
	at java.util.TimerThread.run(Timer.java:462)

Comment 3 Joakim Erdfelt

2010-05-24 17:18:15 EDT

Another NPE discovered ...

2010-05-24 14:14:14.734:WARN::/server
java.lang.NullPointerException
	at org.eclipse.jetty.server.session.AbstractSessionMigrationTest$TestServlet.doPost(AbstractSessionMigrationTest.java:131)
	at org.eclipse.jetty.server.session.AbstractSessionMigrationTest$TestServlet.doGet(AbstractSessionMigrationTest.java:111)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:527)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:423)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:924)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:358)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:183)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:860)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:245)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:113)
	at org.eclipse.jetty.server.Server.handle(Server.java:335)
	at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:588)
	at org.eclipse.jetty.server.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:1029)
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:549)
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:211)
	at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:418)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:489)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:436)
	at java.lang.Thread.run(Thread.java:619)

Comment 4 Joakim Erdfelt

2010-05-24 17:41:49 EDT

Fixed in r1856 by removing testng, and using a maven target directory for derby.system.home (to eliminate bugs in testing introduced with shared /tmp directory)