diff --git a/src/e2e/java/teammates/e2e/cases/SystemErrorEmailReportE2ETest.java b/src/e2e/java/teammates/e2e/cases/SystemErrorEmailReportE2ETest.java index cbd55713df6..5750c24191f 100644 --- a/src/e2e/java/teammates/e2e/cases/SystemErrorEmailReportE2ETest.java +++ b/src/e2e/java/teammates/e2e/cases/SystemErrorEmailReportE2ETest.java @@ -4,6 +4,7 @@ import com.google.cloud.datastore.DatastoreException; +import teammates.common.exception.DeadlineExceededException; import teammates.common.exception.EntityNotFoundException; import teammates.common.exception.InvalidHttpParameterException; import teammates.common.exception.UnauthorizedAccessException; @@ -29,6 +30,7 @@ protected void prepareBrowser() { public void testAll() { testAssertionError(); testNullPointerException(); + testDeadlineExceededException(); testDatastoreException(); testUnauthorizedAccessException(); testInvalidHttpParameterException(); @@ -63,6 +65,20 @@ private void testNullPointerException() { } + private void testDeadlineExceededException() { + + ______TS("DeadlineExceededException testing"); + + String url = createUrl(Const.ResourceURIs.EXCEPTION) + .withParam(Const.ParamsNames.ERROR, DeadlineExceededException.class.getSimpleName()) + .toString(); + + BACKDOOR.executeGetRequest(url, null); + + print("DeadlineExceededException triggered, verify that you have received error logs via email"); + + } + private void testDatastoreException() { ______TS("DatastoreException testing"); diff --git a/src/main/java/teammates/common/exception/DeadlineExceededException.java b/src/main/java/teammates/common/exception/DeadlineExceededException.java new file mode 100644 index 00000000000..271918183aa --- /dev/null +++ b/src/main/java/teammates/common/exception/DeadlineExceededException.java @@ -0,0 +1,7 @@ +package teammates.common.exception; + +/** + * Exception thrown when an operation is determined to have exceeded the time it is allowed to run. + */ +public class DeadlineExceededException extends RuntimeException { +} diff --git a/src/main/java/teammates/common/util/RequestTracer.java b/src/main/java/teammates/common/util/RequestTracer.java index b751e3f0969..d908f5c378e 100644 --- a/src/main/java/teammates/common/util/RequestTracer.java +++ b/src/main/java/teammates/common/util/RequestTracer.java @@ -3,6 +3,8 @@ import java.time.Instant; import java.time.temporal.ChronoUnit; +import teammates.common.exception.DeadlineExceededException; + /** * Stores the information of the current HTTP request. */ @@ -39,14 +41,25 @@ public static String getSpanId() { /** * Returns the remaining time (in millis) until the current request times out. */ - public static long getRemainingTimeMillis() { + private static long getRemainingTimeMillis() { RequestTrace trace = THREAD_LOCAL.get(); if (trace == null) { - return -1L; + return 1L; } return trace.timeoutTimestamp - Instant.now().toEpochMilli(); } + /** + * Throws {@link DeadlineExceededException} if the current thread has exceeded + * the limit for serving request. + */ + public static void checkRemainingTime() { + long remainingTime = getRemainingTimeMillis(); + if (remainingTime < 0) { + throw new DeadlineExceededException(); + } + } + /** * Returns the remaining time (in millis) until the current request times out. */ diff --git a/src/main/java/teammates/logic/api/EmailGenerator.java b/src/main/java/teammates/logic/api/EmailGenerator.java index ee846a6a841..193a7391fc4 100644 --- a/src/main/java/teammates/logic/api/EmailGenerator.java +++ b/src/main/java/teammates/logic/api/EmailGenerator.java @@ -21,6 +21,7 @@ import teammates.common.util.EmailType; import teammates.common.util.EmailWrapper; import teammates.common.util.Logger; +import teammates.common.util.RequestTracer; import teammates.common.util.SanitizationHelper; import teammates.common.util.StringHelper; import teammates.common.util.Templates; @@ -275,6 +276,7 @@ private EmailWrapper generateSessionLinksRecoveryEmailForExistingStudent(String List sessions = fsLogic.getAllFeedbackSessionsWithinTimeRange(startTime, endTime); for (FeedbackSessionAttributes session : sessions) { + RequestTracer.checkRemainingTime(); String courseId = session.getCourseId(); CourseAttributes course = coursesLogic.getCourse(courseId); List students = studentsForEmail.stream().filter( diff --git a/src/main/java/teammates/logic/core/FeedbackSessionsLogic.java b/src/main/java/teammates/logic/core/FeedbackSessionsLogic.java index 47810e62f2c..62e1616d509 100644 --- a/src/main/java/teammates/logic/core/FeedbackSessionsLogic.java +++ b/src/main/java/teammates/logic/core/FeedbackSessionsLogic.java @@ -30,6 +30,7 @@ import teammates.common.exception.InvalidParametersException; import teammates.common.util.Const; import teammates.common.util.Logger; +import teammates.common.util.RequestTracer; import teammates.common.util.TimeHelper; import teammates.storage.api.FeedbackSessionsDb; @@ -532,6 +533,7 @@ public SessionResultsBundle getSessionResultsForUser( for (FeedbackQuestionAttributes qn : allQuestions) { allQuestionsMap.put(qn.getId(), qn); } + RequestTracer.checkRemainingTime(); // load response(s) StudentAttributes student = getStudent(courseId, userEmail, role); @@ -556,6 +558,7 @@ public SessionResultsBundle getSessionResultsForUser( allResponses.addAll(viewableResponses); } } + RequestTracer.checkRemainingTime(); // load comment(s) List allComments; @@ -564,6 +567,7 @@ public SessionResultsBundle getSessionResultsForUser( } else { allComments = frcLogic.getFeedbackResponseCommentForQuestionInSection(questionId, section); } + RequestTracer.checkRemainingTime(); // related questions, responses, and comment Map relatedQuestionsMap = new HashMap<>(); @@ -610,6 +614,7 @@ public SessionResultsBundle getSessionResultsForUser( responseRecipientVisibilityTable.put(response.getId(), frLogic.isNameVisibleToUser(correspondingQuestion, response, userEmail, role, false, roster)); } + RequestTracer.checkRemainingTime(); // build comment for (FeedbackResponseCommentAttributes frc : allComments) { @@ -630,6 +635,7 @@ public SessionResultsBundle getSessionResultsForUser( // generate comment giver name visibility table commentVisibilityTable.put(frc.getId(), frcLogic.isNameVisibleToUser(frc, relatedResponse, userEmail, roster)); } + RequestTracer.checkRemainingTime(); List existingResponses = new ArrayList<>(relatedResponsesMap.values()); List missingResponses = Collections.emptyList(); @@ -639,6 +645,7 @@ public SessionResultsBundle getSessionResultsForUser( instructor, responseGiverVisibilityTable, responseRecipientVisibilityTable, session, relatedQuestionsMap, existingResponses, roster, section); } + RequestTracer.checkRemainingTime(); return new SessionResultsBundle(session, relatedQuestionsMap, existingResponses, missingResponses, responseGiverVisibilityTable, responseRecipientVisibilityTable, relatedCommentsMap, diff --git a/src/main/java/teammates/logic/core/StudentsLogic.java b/src/main/java/teammates/logic/core/StudentsLogic.java index 1df70383d35..9490602156d 100644 --- a/src/main/java/teammates/logic/core/StudentsLogic.java +++ b/src/main/java/teammates/logic/core/StudentsLogic.java @@ -14,6 +14,7 @@ import teammates.common.exception.RegenerateStudentException; import teammates.common.exception.SearchServiceException; import teammates.common.util.Const; +import teammates.common.util.RequestTracer; import teammates.storage.api.StudentsDb; /** @@ -333,6 +334,7 @@ private String getTeamInvalidityInfo(List mergedList) { public void deleteStudentsInCourseCascade(String courseId) { List studentsInCourse = getStudentsForCourse(courseId); for (StudentAttributes student : studentsInCourse) { + RequestTracer.checkRemainingTime(); deleteStudentCascade(courseId, student.email); } } diff --git a/src/main/java/teammates/ui/webapi/AdminExceptionTestAction.java b/src/main/java/teammates/ui/webapi/AdminExceptionTestAction.java index 7eba55dd054..73d7499346a 100644 --- a/src/main/java/teammates/ui/webapi/AdminExceptionTestAction.java +++ b/src/main/java/teammates/ui/webapi/AdminExceptionTestAction.java @@ -3,6 +3,7 @@ import com.google.cloud.datastore.DatastoreException; import com.google.rpc.Code; +import teammates.common.exception.DeadlineExceededException; import teammates.common.exception.EntityDoesNotExistException; import teammates.common.exception.EntityNotFoundException; import teammates.common.exception.InvalidHttpParameterException; @@ -41,6 +42,9 @@ JsonResult execute() { if (error.equals(NullPointerException.class.getSimpleName())) { throw new NullPointerException("NullPointerException testing"); } + if (error.equals(DeadlineExceededException.class.getSimpleName())) { + throw new DeadlineExceededException(); + } if (error.equals(DatastoreException.class.getSimpleName())) { throw new DatastoreException(Code.DEADLINE_EXCEEDED_VALUE, "DatastoreException testing", Code.DEADLINE_EXCEEDED.name()); diff --git a/src/main/java/teammates/ui/webapi/EnrollStudentsAction.java b/src/main/java/teammates/ui/webapi/EnrollStudentsAction.java index 86f2de68157..743bf86579b 100644 --- a/src/main/java/teammates/ui/webapi/EnrollStudentsAction.java +++ b/src/main/java/teammates/ui/webapi/EnrollStudentsAction.java @@ -14,6 +14,7 @@ import teammates.common.exception.InvalidParametersException; import teammates.common.exception.UnauthorizedAccessException; import teammates.common.util.Const; +import teammates.common.util.RequestTracer; import teammates.ui.output.EnrollStudentsData; import teammates.ui.output.StudentsData; import teammates.ui.request.StudentsEnrollRequest; @@ -73,7 +74,8 @@ JsonResult execute() { existingStudents.stream().map(StudentAttributes::getEmail).collect(Collectors.toSet()); List enrolledStudents = new ArrayList<>(); List failToEnrollStudents = new ArrayList<>(); - studentsToEnroll.forEach(student -> { + for (StudentAttributes student : studentsToEnroll) { + RequestTracer.checkRemainingTime(); if (existingStudentsEmail.contains(student.email)) { // The student has been enrolled in the course. StudentAttributes.UpdateOptions updateOptions = @@ -103,7 +105,7 @@ JsonResult execute() { exception.getMessage())); } } - }); + } return new JsonResult(new EnrollStudentsData(new StudentsData(enrolledStudents), failToEnrollStudents)); } } diff --git a/src/main/java/teammates/ui/webapi/FeedbackSessionClosedRemindersAction.java b/src/main/java/teammates/ui/webapi/FeedbackSessionClosedRemindersAction.java index 2af83b5ebd3..f7229c50dff 100644 --- a/src/main/java/teammates/ui/webapi/FeedbackSessionClosedRemindersAction.java +++ b/src/main/java/teammates/ui/webapi/FeedbackSessionClosedRemindersAction.java @@ -6,6 +6,7 @@ import teammates.common.exception.TeammatesException; import teammates.common.util.EmailWrapper; import teammates.common.util.Logger; +import teammates.common.util.RequestTracer; /** * Cron job: schedules feedback session closed emails to be sent. @@ -19,6 +20,7 @@ JsonResult execute() { List sessions = logic.getFeedbackSessionsClosedWithinThePastHour(); for (FeedbackSessionAttributes session : sessions) { + RequestTracer.checkRemainingTime(); List emailsToBeSent = emailGenerator.generateFeedbackSessionClosedEmails(session); try { taskQueuer.scheduleEmailsForSending(emailsToBeSent); diff --git a/src/main/java/teammates/ui/webapi/FeedbackSessionClosingRemindersAction.java b/src/main/java/teammates/ui/webapi/FeedbackSessionClosingRemindersAction.java index 58f14a27f47..3c598cae94e 100644 --- a/src/main/java/teammates/ui/webapi/FeedbackSessionClosingRemindersAction.java +++ b/src/main/java/teammates/ui/webapi/FeedbackSessionClosingRemindersAction.java @@ -6,6 +6,7 @@ import teammates.common.exception.TeammatesException; import teammates.common.util.EmailWrapper; import teammates.common.util.Logger; +import teammates.common.util.RequestTracer; /** * Cron job: schedules feedback session closing emails to be sent. @@ -19,6 +20,7 @@ JsonResult execute() { List sessions = logic.getFeedbackSessionsClosingWithinTimeLimit(); for (FeedbackSessionAttributes session : sessions) { + RequestTracer.checkRemainingTime(); List emailsToBeSent = emailGenerator.generateFeedbackSessionClosingEmails(session); try { taskQueuer.scheduleEmailsForSending(emailsToBeSent); diff --git a/src/main/java/teammates/ui/webapi/FeedbackSessionOpeningRemindersAction.java b/src/main/java/teammates/ui/webapi/FeedbackSessionOpeningRemindersAction.java index 832100f11f9..f028e8947e1 100644 --- a/src/main/java/teammates/ui/webapi/FeedbackSessionOpeningRemindersAction.java +++ b/src/main/java/teammates/ui/webapi/FeedbackSessionOpeningRemindersAction.java @@ -6,6 +6,7 @@ import teammates.common.exception.TeammatesException; import teammates.common.util.EmailWrapper; import teammates.common.util.Logger; +import teammates.common.util.RequestTracer; /** * Cron job: schedules feedback session opening emails to be sent. @@ -19,6 +20,7 @@ JsonResult execute() { List sessions = logic.getFeedbackSessionsWhichNeedOpenEmailsToBeSent(); for (FeedbackSessionAttributes session : sessions) { + RequestTracer.checkRemainingTime(); List emailsToBeSent = emailGenerator.generateFeedbackSessionOpeningEmails(session); try { taskQueuer.scheduleEmailsForSending(emailsToBeSent); diff --git a/src/main/java/teammates/ui/webapi/FeedbackSessionPublishedRemindersAction.java b/src/main/java/teammates/ui/webapi/FeedbackSessionPublishedRemindersAction.java index 364a8f69381..2dc497f9308 100644 --- a/src/main/java/teammates/ui/webapi/FeedbackSessionPublishedRemindersAction.java +++ b/src/main/java/teammates/ui/webapi/FeedbackSessionPublishedRemindersAction.java @@ -3,6 +3,7 @@ import java.util.List; import teammates.common.datatransfer.attributes.FeedbackSessionAttributes; +import teammates.common.util.RequestTracer; /** * Cron job: schedules feedback session published emails to be sent. @@ -14,6 +15,7 @@ JsonResult execute() { List sessions = logic.getFeedbackSessionsWhichNeedAutomatedPublishedEmailsToBeSent(); for (FeedbackSessionAttributes session : sessions) { + RequestTracer.checkRemainingTime(); taskQueuer.scheduleFeedbackSessionPublishedEmail(session.getCourseId(), session.getFeedbackSessionName()); } return new JsonResult("Successful"); diff --git a/src/main/java/teammates/ui/webapi/RequestTraceFilter.java b/src/main/java/teammates/ui/webapi/RequestTraceFilter.java index b6d27d563d4..9807aae0f9a 100644 --- a/src/main/java/teammates/ui/webapi/RequestTraceFilter.java +++ b/src/main/java/teammates/ui/webapi/RequestTraceFilter.java @@ -4,16 +4,11 @@ import java.util.HashMap; import java.util.Map; import java.util.Random; -import java.util.concurrent.ExecutionException; -import java.util.concurrent.ExecutorService; -import java.util.concurrent.Executors; -import java.util.concurrent.Future; -import java.util.concurrent.TimeUnit; -import java.util.concurrent.TimeoutException; import javax.servlet.Filter; import javax.servlet.FilterChain; import javax.servlet.FilterConfig; +import javax.servlet.ServletException; import javax.servlet.ServletRequest; import javax.servlet.ServletResponse; import javax.servlet.http.HttpServletRequest; @@ -22,7 +17,6 @@ import org.apache.commons.codec.binary.Hex; import org.apache.http.HttpStatus; -import teammates.common.exception.TeammatesException; import teammates.common.util.Config; import teammates.common.util.HttpRequestHelper; import teammates.common.util.LogEvent; @@ -42,30 +36,30 @@ public void init(FilterConfig filterConfig) { } @Override - public void doFilter(ServletRequest req, ServletResponse resp, FilterChain chain) throws IOException { + public void doFilter(ServletRequest req, ServletResponse resp, FilterChain chain) throws IOException, ServletException { HttpServletResponse response = (HttpServletResponse) resp; response.setHeader("Strict-Transport-Security", "max-age=31536000"); response.setHeader("Cache-Control", "no-store"); response.setHeader("Pragma", "no-cache"); - if (Config.MAINTENANCE) { - throwError(response, HttpStatus.SC_SERVICE_UNAVAILABLE, - "The server is currently undergoing some maintenance."); - return; - } - HttpServletRequest request = (HttpServletRequest) req; - try { - // Make sure that all parameters are valid UTF-8 - request.getParameterMap(); - } catch (RuntimeException e) { - if (e.getClass().getSimpleName().equals("BadMessageException")) { - throwError(response, HttpStatus.SC_BAD_REQUEST, e.getMessage()); - return; + String requestId = request.getHeader("X-Cloud-Trace-Context"); + String traceId; + String spanId = null; + if (requestId == null) { + // Generate random hexadecimal string of length 32 + byte[] resBuf = new byte[16]; + new Random().nextBytes(resBuf); + traceId = Hex.encodeHexString(resBuf); + } else { + // X-Cloud-Trace-Context header is in form of TRACE_ID/SPAN_ID;o=TRACE_TRUE + String[] traceAndSpan = requestId.split("/", 2); + traceId = traceAndSpan[0]; + if (traceAndSpan.length == 2) { + spanId = traceAndSpan[1].split(";")[0]; } - throw e; } // The header X-AppEngine-QueueName cannot be spoofed as GAE will strip any user-sent X-AppEngine-QueueName headers. @@ -78,57 +72,38 @@ public void doFilter(ServletRequest req, ServletResponse resp, FilterChain chain // For user-invoked requests, we keep the time limit at 1 minute (as how it was // in the previous GAE runtime environment) in order to not let user wait for excessively long, // as well as a reminder for us to keep optimizing our API response time. - int timeoutInSeconds = isRequestFromAppEngineQueue ? 10 * 60 - 5 : 60; - - ExecutorService es = Executors.newSingleThreadExecutor(); - Future f = es.submit(() -> { - String requestId = request.getHeader("X-Cloud-Trace-Context"); - String traceId; - String spanId = null; - if (requestId == null) { - // Generate random hexadecimal string of length 32 - byte[] resBuf = new byte[16]; - new Random().nextBytes(resBuf); - traceId = Hex.encodeHexString(resBuf); - } else { - // X-Cloud-Trace-Context header is in form of TRACE_ID/SPAN_ID;o=TRACE_TRUE - String[] traceAndSpan = requestId.split("/", 2); - traceId = traceAndSpan[0]; - if (traceAndSpan.length == 2) { - spanId = traceAndSpan[1].split(";")[0]; - } - } - RequestTracer.init(traceId, spanId, timeoutInSeconds); + int timeoutInSeconds = isRequestFromAppEngineQueue ? 10 * 60 - 5 : 10; - Map requestDetails = new HashMap<>(); - requestDetails.put("requestMethod", request.getMethod()); - requestDetails.put("requestUrl", request.getRequestURI()); - requestDetails.put("userAgent", request.getHeader("User-Agent")); - requestDetails.put("requestParams", HttpRequestHelper.getRequestParameters(request)); - requestDetails.put("requestHeaders", HttpRequestHelper.getRequestHeaders(request)); + RequestTracer.init(traceId, spanId, timeoutInSeconds); - String message = "Request " + RequestTracer.getTraceId() + " received: " + request.getRequestURI(); - log.event(LogEvent.REQUEST_RECEIVED, message, requestDetails); + Map requestDetails = new HashMap<>(); + requestDetails.put("requestMethod", request.getMethod()); + requestDetails.put("requestUrl", request.getRequestURI()); + requestDetails.put("userAgent", request.getHeader("User-Agent")); + requestDetails.put("requestParams", HttpRequestHelper.getRequestParameters(request)); + requestDetails.put("requestHeaders", HttpRequestHelper.getRequestHeaders(request)); - chain.doFilter(req, resp); - return null; - }); + String message = "Request " + RequestTracer.getTraceId() + " received: " + request.getRequestURI(); + log.event(LogEvent.REQUEST_RECEIVED, message, requestDetails); + + if (Config.MAINTENANCE) { + throwError(response, HttpStatus.SC_SERVICE_UNAVAILABLE, + "The server is currently undergoing some maintenance."); + return; + } try { - f.get(timeoutInSeconds, TimeUnit.SECONDS); - } catch (InterruptedException | ExecutionException e) { - log.severe(e.getClass().getSimpleName() + " caught by WebApiServlet: " - + TeammatesException.toStringWithStackTrace(e)); - throwError(response, HttpStatus.SC_INTERNAL_SERVER_ERROR, e.getMessage()); - } catch (TimeoutException e) { - log.severe("TimeoutException caught by WebApiServlet: " - + TeammatesException.toStringWithStackTrace(e)); - throwError(response, HttpStatus.SC_GATEWAY_TIMEOUT, - "The request exceeded the server timeout limit. Please try again later."); - } finally { - f.cancel(true); - es.shutdown(); + // Make sure that all parameters are valid UTF-8 + request.getParameterMap(); + } catch (RuntimeException e) { + if (e.getClass().getSimpleName().equals("BadMessageException")) { + throwError(response, HttpStatus.SC_BAD_REQUEST, e.getMessage()); + return; + } + throw e; } + + chain.doFilter(req, resp); } @Override diff --git a/src/main/java/teammates/ui/webapi/WebApiServlet.java b/src/main/java/teammates/ui/webapi/WebApiServlet.java index 279bf77218d..d7fcc6046a1 100644 --- a/src/main/java/teammates/ui/webapi/WebApiServlet.java +++ b/src/main/java/teammates/ui/webapi/WebApiServlet.java @@ -14,6 +14,7 @@ import com.google.cloud.datastore.DatastoreException; import teammates.common.exception.ActionMappingException; +import teammates.common.exception.DeadlineExceededException; import teammates.common.exception.EntityNotFoundException; import teammates.common.exception.InvalidHttpParameterException; import teammates.common.exception.InvalidHttpRequestBodyException; @@ -87,6 +88,11 @@ private void invokeServlet(HttpServletRequest req, HttpServletResponse resp) thr log.warning(enfe.getClass().getSimpleName() + " caught by WebApiServlet: " + TeammatesException.toStringWithStackTrace(enfe)); throwError(resp, statusCode, enfe.getMessage()); + } catch (DeadlineExceededException dee) { + statusCode = HttpStatus.SC_GATEWAY_TIMEOUT; + log.severe("TimeoutException caught by WebApiServlet: " + + TeammatesException.toStringWithStackTrace(dee)); + throwError(resp, statusCode, "The request exceeded the server timeout limit. Please try again later."); } catch (DatastoreException e) { statusCode = HttpStatus.SC_INTERNAL_SERVER_ERROR; log.severe(e.getClass().getSimpleName() + " caught by WebApiServlet: "