nus-oss-test / testrepo4

TEAMMATES system is online at
http://teammatesv4.appspot.com
0 stars 0 forks source link

InstructorCourseEnrollSaveAction failed due to null parameter #1725

Closed damithc closed 10 years ago

damithc commented 10 years ago

From dam...@gmail.com on March 03, 2014 19:14:10

This happened in the middle of a session, so it cannot be an expired session. cache?

Request Path /page Request Parameters {user::abc, courseid::GEK1548} Stack Trace

java.lang.AssertionError: null at teammates.common.util.Assumption.fail(Assumption.java:56) at teammates.common.util.Assumption.assertTrue(Assumption.java:25) at teammates.common.util.Assumption.assertNotNull(Assumption.java:252) at teammates.common.util.Assumption.assertNotNull(Assumption.java:244) at teammates.ui.controller.InstructorCourseEnrollSaveAction.execute(InstructorCourseEnrollSaveAction.java:27) at teammates.ui.controller.Action.executeAndPostProcess(Action.java:125) at teammates.ui.controller.ControllerServlet.doPost(ControllerServlet.java:48) at teammates.ui.controller.ControllerServlet.doGet(ControllerServlet.java:34) at javax.servlet.http.HttpServlet.service(HttpServlet.java:617) at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166) at teammates.ui.controller.LoginFilter.doFilter(LoginFilter.java:46) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at teammates.storage.datastore.DatastoreFilter.doFilter(DatastoreFilter.java:28) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.google.appengine.tools.appstats.AppstatsFilter.doFilter(AppstatsFilter.java:141) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.google.apphosting.utils.servlet.JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter.java:60) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388) at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216) at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418) at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:266) at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) at org.mortbay.jetty.Server.handle(Server.java:326) at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923) at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76) at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:146) at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(JavaRuntime.java:446) at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:437) at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:444) at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:188) at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:308) at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:300) at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:441) at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:251) at java.lang.Thread.run(Thread.java:724)

Original issue: http://code.google.com/p/teammatespes/issues/detail?id=1670

damithc commented 10 years ago

From dam...@gmail.com on March 07, 2014 02:41:55

This happened again to a different user. I noticed that in both cases the same request came it twice within a few seconds, and the 2nd one caused the exception.

2014-03-03 18:13:46.196 /page/instructorCourseEnrollSave?courseid=GEK1548&user=TanMengHo 302 349ms 0kb Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; Trident/5.0; GTB7.5) module=default version=4-89 137.132.252.191 - abc[03/Mar/2014:02:13:46 -0800] "GET /page/instructorCourseEnrollSave?courseid=GEK1548&user=abc HTTP/1.1" 302 117 " https://accounts.google.com/ServiceLogin?service=ah&passive=true&continue=https%3A%2F%2Fappengine.google.com%2F_ah%2Fconflogin%3Fcontinue%3Dhttps%3A%2F%2Fteammatesv4.appspot.com%2Fpage%2FinstructorCourseEnrollSave%253Fcourseid%253DGEK1548%2526user%253DTanMengHo&ltmpl=gm&shdf=CicLEgZhaG5hbWUaG1RFQU1NQVRFUyBQZWVyIEV2YWwuIFN5c3RlbQwSAmFoIhTFlsHGkCxW4yDNIbF6Ldsk_QmAqSgBMhRpbw3J20sCPNbJDmWIU_l-oMNSTg " "Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; Trident/5.0; GTB7.5)" "teammatesv4.appspot.com" ms=350 cpu_ms=47 cpm_usd=0.100519 app_engine_release=1.9.0 instance=00c61b117c491120dfb51cb804cc7019753ca183 I 2014-03-03 18:13:45.850 teammates.ui.controller.ActionFactory getAction: URL received : https://teammatesv4.appspot.com/page/instructorCourseEnrollSave I 2014-03-03 18:13:45.884 teammates.logic.core.Emails sendEmail: [Email sent]to=teammates@comp.nus.edu.sg|from="TEAMMATES Admin (noreply)" noreply@teammatesv4.appspotmail.com|subject=TEAMMATES (4.89): New System Exception: null E 2014-03-03 18:13:46.100 teammates.logic.core.Emails sendErrorReport: Sent crash report: [Email sent]to=teammates@comp.nus.edu.sg|from="TEAMMATES Admin (noreply)" noreply@teammatesv4.appspotmail.com|subject=TEAMMATES (4.89): New System Exception: null E 2014-03-03 18:13:46.100 teammates.ui.controller.ControllerServlet doPost: TEAMMATESLOG|||page|||System Error Report|||true|||Unknown|||Unknown|||Unknown|||Unknown|||TEAMMATES (4.89): New System Exception: null
Show/Hide Details >>


null


Request Path /page

Request Parameters {user::TanMengHo, courseid::GEK1548}

Stack Trace


java.lang.AssertionError: null
    at teammates.common.util.Assumption.fail(Assumption.java:56)
    at teammates.common.util.Assumption.assertTrue(Assumption.java:25)
    at teammates.common.util.Assumption.assertNotNull(Assumption.java:252)
    at teammates.common.util.Assumption.assertNotNull(Assumption.java:244)
    at teammates.ui.controller.InstructorCourseEnrollSaveAction.execute(InstructorCourseEnrollSaveAction.java:27)
    at teammates.ui.controller.Action.executeAndPostProcess(Action.java:125)
    at teammates.ui.controller.ControllerServlet.doPost(ControllerServlet.java:48)
    at teammates.ui.controller.ControllerServlet.doGet(ControllerServlet.java:34)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
    at teammates.ui.controller.LoginFilter.doFilter(LoginFilter.java:46)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at teammates.storage.datastore.DatastoreFilter.doFilter(DatastoreFilter.java:28)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.appstats.AppstatsFilter.doFilter(AppstatsFilter.java:141)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter.java:60)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
    at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:266)
    at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    at org.mortbay.jetty.Server.handle(Server.java:326)
    at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
    at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
    at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
    at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
    at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:146)
    at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(JavaRuntime.java:446)
    at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:437)
    at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:444)
    at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:188)
    at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:308)
    at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:300)
    at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:441)
    at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:251)
    at java.lang.Thread.run(Thread.java:724)

|||/page/instructorCourseEnrollSave?courseid=GEK1548&user=abc

2014-03-03 18:13:34.225 /page/instructorCourseEnrollSave?courseid=GEK1548&user=abc 302 92ms 0kb Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; Trident/5.0) module=default version=4-89 137.132.252.191 - - [03/Mar/2014:02:13:34 -0800] "POST /page/instructorCourseEnrollSave?courseid=GEK1548&user=abc HTTP/1.1" 302 45...

damithc commented 10 years ago

From dam...@gmail.com on March 07, 2014 02:41:55

...4 " https://teammatesv4.appspot.com/page/instructorCourseEnrollPage?courseid=GEK1548&user=abc " "Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; Trident/5.0)" "teammatesv4.appspot.com" ms=92 cpu_ms=23 cpm_usd=0.000051 app_engine_release=1.9.0 instance=00c61b117c491120dfb51cb804cc7019753ca183

damithc commented 10 years ago

From dam...@gmail.com on March 07, 2014 02:46:44

Even more strange is that the first request (shown 2nd in the above stack trace) did not write to the admin log. It's as if the request was split in half and the first one had the data but did not complete while the 2nd one did not have the data but try to complete. :-p I'll keep monitoring the situation.

damithc commented 10 years ago

From leeshaw...@gmail.com on March 07, 2014 03:12:52

Does it have something to do with this particular course "GEK1548"? Not sure if there is a connection but both stack trace seems to have the same course ID.

damithc commented 10 years ago

From dam...@gmail.com on March 07, 2014 03:15:05

It is the same stack trace. I didn't post the recent one.

damithc commented 10 years ago

From dam...@gmail.com on March 07, 2014 06:13:30

Another case, for a different page. Two requests within 11 seconds, both failed.

2014-03-07 21:03:28.811 /page/instructorFeedbackPreviewAsStudent 302 252ms 0kb Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; rv:11.0) like Gecko module=default version=4-89 209.59.74.4 - lawsonmorton [07/Mar/2014:05:03:28 -0800] "POST /page/instructorFeedbackPreviewAsStudent HTTP/1.1" 302 117 " https://teammatesv4.appspot.com/page/instructorFeedbackEditPage?courseid=Gross-Anatomy-Peer-Eval-Spring-2014&fsname=Group+Participation+Evaluation&user=xyz&message=The+question+has+been+added+to+this+feedback+session.&error=false " "Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; rv:11.0) like Gecko" "teammatesv4.appspot.com" ms=252 cpu_ms=43 cpm_usd=0.100503 app_engine_release=1.9.0 instance=00c61b117cab158ee7011bbc20a2cce2ddaeb9 I 2014-03-07 21:03:28.572 teammates.ui.controller.ActionFactory getAction: URL received : https://teammatesv4.appspot.com/page/instructorFeedbackPreviewAsStudent I 2014-03-07 21:03:28.598 teammates.logic.core.Emails sendEmail: [Email sent]to=teammates@comp.nus.edu.sg|from="TEAMMATES Admin (noreply)" noreply@teammatesv4.appspotmail.com|subject=TEAMMATES (4.89): New System Exception: null E 2014-03-07 21:03:28.805 teammates.logic.core.Emails sendErrorReport: Sent crash report: [Email sent]to=teammates@comp.nus.edu.sg|from="TEAMMATES Admin (noreply)" noreply@teammatesv4.appspotmail.com|subject=TEAMMATES (4.89): New System Exception: null E 2014-03-07 21:03:28.806 teammates.ui.controller.ControllerServlet doPost: TEAMMATESLOG|||page|||System Error Report|||true|||Unknown|||Unknown|||Unknown|||Unknown|||TEAMMATES (4.89): New System Exception: null
Show/Hide Details >>


null


Request Path /page

Request Parameters {user::lawsonmorton, courseid::Gross-Anatomy-Peer-Eval-Spring-2014, fsname::Group Participation Evaluation}

Stack Trace


java.lang.AssertionError: null
    at teammates.common.util.Assumption.fail(Assumption.java:56)
    at teammates.common.util.Assumption.fail(Assumption.java:63)
    at teammates.ui.controller.InstructorFeedbackPreviewAsStudentAction.execute(InstructorFeedbackPreviewAsStudentAction.java:17)
    at teammates.ui.controller.Action.executeAndPostProcess(Action.java:125)
    at teammates.ui.controller.ControllerServlet.doPost(ControllerServlet.java:48)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
    at teammates.ui.controller.LoginFilter.doFilter(LoginFilter.java:46)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at teammates.storage.datastore.DatastoreFilter.doFilter(DatastoreFilter.java:28)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.appstats.AppstatsFilter.doFilter(AppstatsFilter.java:141)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter.java:60)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
    at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:266)
    at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    at org.mortbay.jetty.Server.handle(Server.java:326)
    at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
    at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
    at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
    at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
    at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:146)
    at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(JavaRuntime.java:446)
    at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:437)
    at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:444)
    at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:188)
    at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:308)
    at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:300)
    at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:441)
    at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:251)
    at java.lang.Thread.run(Thread.java:724)

|||/page/instructorFeedbackPreviewAsStudent

damithc commented 10 years ago

From leeshaw...@gmail.com on March 07, 2014 06:35:51

I will try to do some extensive testing over the next few days to see if I can reproduce it. Based on the above, seems like the exceptions tend to occur when 2 requests are made within a short time frame.

damithc commented 10 years ago

From dam...@gmail.com on March 07, 2014 06:39:33

May be create a test to hit the server rapidly with bursts of requests? The first thing to do is to reproduce the error. Another thing we can do is to log the parameters at the beginning of the request. Also try doubleclicking the button to see if that reproduce the error.

damithc commented 10 years ago

From dam...@gmail.com on March 07, 2014 18:03:46

Another one with the same pattern:

2014-03-08 01:38:12.338 /page/studentCourseJoin 302 395ms 0kb Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.146 Safari/537.36 module=default version=4-89 204.234.199.100 - andrew.sell [07/Mar/2014:09:38:12 -0800] "GET /page/studentCourseJoin HTTP/1.1" 302 117 - "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.146 Safari/537.36" "teammatesv4.appspot.com" ms=396 cpu_ms=46 cpm_usd=0.100513 app_engine_release=1.9.0 instance=00c61b117c50110e6c02238e327f3fd52ca1870b I 2014-03-08 01:38:11.946 teammates.ui.controller.ActionFactory getAction: URL received : https://teammatesv4.appspot.com/page/studentCourseJoin I 2014-03-08 01:38:12.037 teammates.logic.core.Emails sendEmail: [Email sent]to=teammates@comp.nus.edu.sg|from="TEAMMATES Admin (noreply)" noreply@teammatesv4.appspotmail.com|subject=TEAMMATES (4.89): New System Exception: null E 2014-03-08 01:38:12.307 teammates.logic.core.Emails sendErrorReport: Sent crash report: [Email sent]to=teammates@comp.nus.edu.sg|from="TEAMMATES Admin (noreply)" noreply@teammatesv4.appspotmail.com|subject=TEAMMATES (4.89): New System Exception: null E 2014-03-08 01:38:12.307 teammates.ui.controller.ControllerServlet doPost: TEAMMATESLOG|||page|||System Error Report|||true|||Unknown|||Unknown|||Unknown|||Unknown|||TEAMMATES (4.89): New System Exception: null
Show/Hide Details >>


null


Request Path /page

Request Parameters {}

Stack Trace


java.lang.AssertionError: null
    at teammates.common.util.Assumption.fail(Assumption.java:56)
    at teammates.common.util.Assumption.assertTrue(Assumption.java:25)
    at teammates.common.util.Assumption.assertNotNull(Assumption.java:252)
    at teammates.common.util.Assumption.assertNotNull(Assumption.java:244)
    at teammates.ui.controller.StudentCourseJoinAction.execute(StudentCourseJoinAction.java:27)
    at teammates.ui.controller.Action.executeAndPostProcess(Action.java:125)
    at teammates.ui.controller.ControllerServlet.doPost(ControllerServlet.java:48)
    at teammates.ui.controller.ControllerServlet.doGet(ControllerServlet.java:34)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
    at teammates.ui.controller.LoginFilter.doFilter(LoginFilter.java:46)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at teammates.storage.datastore.DatastoreFilter.doFilter(DatastoreFilter.java:28)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.appengine.tools.appstats.AppstatsFilter.doFilter(AppstatsFilter.java:141)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter.java:60)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
    at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
    at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
    at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
    at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
    at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
    at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:266)
    at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    at org.mortbay.jetty.Server.handle(Server.java:326)
    at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
    at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
    at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
    at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
    at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:146)
    at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(JavaRuntime.java:446)
    at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:437)
    at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:444)
    at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:188)
    at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:308)
    at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:300)
    at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:441)
    at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:251)
    at java.lang.Thread.run(Thread.java:724)

|||/page/studentCourseJoin

2014-03-08 01:38:11.888 /page/studentCourseJoin 302 5ms 0kb Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.146 Safari/537.36 module=default version=4-89 204.234.199.100 - - [07/Mar/2014:09:38:11 -0800] "GET /page/studentCourseJoin HTTP/1.1" 302 0 - "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.146 Safari/537.36" "teammatesv4.appspot.com" ms=5 cpu_ms=0 app_engine_release=1.9.0

damithc commented 10 years ago

From dam...@gmail.com on March 08, 2014 16:39:22

I added an extra log message to log requests as soon as they are received by our ControllerServlet. It seems the first request doesn't even reach our ControllerServlet, possibly caught by the login filter instead. After the type the usr name and password, they are redirected to the page, but without the post parameters, causing the assertion failure. This is also probably why users don't complain about it. See if that is the case. if it is, we need to see if we can prevent it because users are going to lose what they typed in.

damithc commented 10 years ago

From leeshaw...@gmail.com on March 10, 2014 23:07:14

More or less confirmed that this is the case. Problem occurs when the user is already logged in, but navigates to these pages directly by typing in the URL (probably maybe through auto complete in the URL box or just typing it in manually). Tested this with both the enroll page and feedback preview as student page and both gave the null exception.

And yes it is possible that if the user already types several student details in the enroll students box, but instead of clicking enroll student button, types in the save action URL instead, they will still get the error (although the back button should be able to retrieve what they typed).

Should we show them an error message, or maybe redirect them back to a homepage? Or is there another way we should approach this?

damithc commented 10 years ago

From dam...@gmail.com on March 10, 2014 23:11:01

it's better if we can redirect them to the original page after login, without losing anything previously typed in. if we can't do that, we can show a message informing the user to use the back button to retrieve old values.

damithc commented 10 years ago

From leeshaw...@gmail.com on March 11, 2014 00:57:49

Status: Started

damithc commented 10 years ago

From leeshaw...@gmail.com on March 13, 2014 08:21:54

Added a redirect to instructor home page when a null "enroll student" POST parameter is detected with a message: "You have been redirected to this page due to some missing data in the previous URL. If you have previously typed some data and wish to retrieve it from the previous page, please press the back button."

Controller Servlet also contains a check for future implementations whereby it checks the URL to see if the user is a student or instructor and redirects accordingly. Also added a log message to loginFilter to confirm that our assumption about the cause of the exceptions is correct.

Also added a simple test case for this.

Code ready for review at: https://codereview.appspot.com/75470043

Status: ReadyForReview

Attachment: ss.png

damithc commented 10 years ago

From dam...@gmail.com on March 13, 2014 08:33:29

Status: ChangesRequested

damithc commented 10 years ago

From leeshaw...@gmail.com on March 13, 2014 09:13:05

Made the requested changes.

Code at: https://codereview.appspot.com/75470043/

Status: ReadyForReview

damithc commented 10 years ago

From dam...@gmail.com on March 13, 2014 17:20:50

Minor comment added.

Status: ReadyToMerge

damithc commented 10 years ago

From leeshaw...@gmail.com on March 13, 2014 22:34:44

This issue was updated by revision 7e47b3aa6403 .

damithc commented 10 years ago

From leeshaw...@gmail.com on March 13, 2014 22:35:23

Status: Delivered

damithc commented 10 years ago

From dam...@gmail.com on March 14, 2014 23:34:42

Status: Deployed
Labels: Milestone-V4.91