WeBWorK Main Forum

Student answer submissions take extremely long to process after upgrade to 2.17

Student answer submissions take extremely long to process after upgrade to 2.17

by Chris Ahrendt -
Number of replies: 8

Hello~

We recently upgraded to WebWork 2.17 and MariaDB on a fresh Ubuntu 22.04 server.  Everything seems to be functioning _except_ that when students (not instructors) submit answers, it takes WebWork a _very_ long time to respond.

The timing.log has items like the following:

  • [Tue Aug 16 13:00:45 2022] 2442 1660672845 - [/webwork2/IL_114/Section_3.8/1/] [runTime = 0.068 sec sql_single]

which is when the student loaded the problem, but then later we see:

  • [Tue Aug 16 13:06:50 2022] 2780 1660673210 - [/webwork2/IL_114/Section_3.8/1/] [runTime = 392.103 sec sql_single]
  • [Tue Aug 16 13:07:13 2022] 2427 1660673233 - [/webwork2/IL_114/Section_3.8/1/] [runTime = 393.027 sec sql_single]

This seems to indicate that the student pressed "grade" twice, and it took a very, very long time to process.  According to the students, they simply see the browser's spinning cursor of a webpage loading while this is going on--no feedback returned after clicking "grade".  However, when they leave the problem and then navigate back to it, they see that the number of attempts has increased, and if they got it right, they see that it is now marked correct.

Over in the apache2.log, the POSTs corresponding to the two long runtimes are out of order from the time stamps:

  • [16/Aug/2022:13:00:44 -0500] "GET /webwork2/IL_114/Section_3.8/1/?effectiveUser=...
  • [several more unrelated lines]
  • [16/Aug/2022:13:06:44 -0500] [**unrelated GET**]
  • [16/Aug/2022:13:00:18 -0500] "POST /webwork2/IL_114/Section_3.8/1/ HTTP/1.1" 200 7027 "https://webwork.uwec.edu/webwork2/IL_114/Section_3.8/1/?effectiveUser=...
  • [16/Aug/2022:13:07:06 -0500] [**unrelated**]

So I do not understand this delay, or where the hold up is occurring.  Is it in an issue with apache?  Is it in the database?  Is it WebWork in the rendering of the content since the timing.log says that this took ~392 seconds?

This seems to be happening for every single student submission.  But not for any instructors submissions, or any other WebWork navigation.

Of course we did not have this issue with WW 2.16 with the mysql db backend.  Perhaps I have something misconfigured?

Any insights would be very much appreciated as we have live courses at the moment, and need to have this resolved ASAP.  Thank you!

Chris

In reply to Chris Ahrendt

Re: Student answer submissions take extremely long to process after upgrade to 2.17

by Chris Ahrendt -
As a bit more info to the above.  A student shared a screen shot (attached) of what happens sometime after the processing is allowed to complete.  The "ATTEMPT NOT ACCEPTED" error is not one that I have seen before.  Perhaps this gives some insight into what is going on?

Chris
Attachment ProblemSubmitting3.png
In reply to Chris Ahrendt

Re: Student answer submissions take extremely long to process after upgrade to 2.17

by Glenn Rice -

The reason the students get this message is because they are refreshing the page after submitting the answer.

Most likely the student submits the answer, then it takes a long time, and then the student gets impatient and refreshes the page.  That is when they get this issue.

I am not sure what is causing the lag, but the message is not related.  Nor does it help in diagnosing the issue unfortunately.

In reply to Chris Ahrendt

Re: Student answer submissions take extremely long to process after upgrade to 2.17

by Danny Glin -

If an instructor submits an answer using the "Submit Answers" button rather than the "Check Answers" button does this happen?

Were your courses created from scratch on your new server, or were they imported from either an old course or a course archive?

One notable difference between submitting answers and checking answers is that submitted answers are logged both in the database and to a file.  You can check to see if there are issues inserting records into the [coursename]_past_answer table, though I wouldn't expect this to be the problem since other database inserts seem to work okay.

The other thing to check is whether there are issues writing to the /opt/webwork/courses/[coursename]/answer.log file.

In reply to Danny Glin

Re: Student answer submissions take extremely long to process after upgrade to 2.17

by Chris Ahrendt -
Danny~

As far as we have observed, no instructors have had this issue, even when using the "Submit Answers" button. It is worth noting that all instructor WebWork accounts have been recreated new on this new WebWork server since we moved authentication from LDAP to LTI.

All of the courses and students who are having this issue were copied over from the old server to the new using course archives. We have a few "go-at-your-own-pace" courses, and so they were live when we made the server switch. It turns out that for any test student that I make, I cannot duplicate this issue. So, perhaps the issue is isolated to students that were in the course on the old server and unarchived on the new server.

I compared the answer.log to the timing.log and for one of the long run times, we have:
answer.log:
[Tue Aug 16 13:42:20 2022] |[username]|Section_3.8|6|1 1660675340 1/8
timing.log:
[Tue Aug 16 13:48:52 2022] 3254 1660675732 - [/webwork2/IL_114/Section_3.8/6/] [runTime = 391.693 sec sql_single]

So it seems that the student's answer is logged at the time of submission as expected, but the timing.log indicates that something is holding up the generation of the response. This also makes sense why after submitting an answer and the student does not get a response right away from WebWork, but navigates to "Show Past Answers", their just submitted answer is already there--even though the timing.log indicates something is still holding up the generation of the response.

With the info so far, it seems that it is an issue with students that were in the archived class, unarchived, and then continued on. It has not been observed for any WebWork accounts that are newly created on the new server--at least so far.

I have turned on the full-out WebWork debug logging; however, the issue has not occurred since that has been turned on. Since I am unable to reproduce the issue with any WebWork accounts that I create, I will have to wait until another one of the affected students encounters the issue again to see what the debug log tells us.

Thanks for your quick response, Danny! If this really is contained to old accounts that were copied over, then it will be isolated to a handful of students. In that case, we should be able to find workarounds for them.

I will follow-up with additional info as I continue to observe this issue.

Chris
In reply to Chris Ahrendt

Re: Student answer submissions take extremely long to process after upgrade to 2.17

by Chris Ahrendt -

Hey all~

Looking at the debug logs, I have determined that the issue is with:

WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade

In particular, our WebWork server uses a proxy server for http/https access.  The Perl LWP module does not seem to utilize the proxy, nor does it look at the ENV settings for proxy information. So, it is failing to connect to the LMS and the ~390 sec delay is the timeout length.

It looks like I need to to make the call on line 327 of the SubmitGrade.pm, which is

$response = LWP::UserAgent->new->request($HTTPRequest);

utilize a proxy server.

I found this:

https://stackoverflow.com/questions/12116244/https-proxy-and-lwpuseragent

Which would require editing of the WeBWorK::Authen::LTIAdvanced::SubmitGrade::submit_grade routine which I would like to avoid if at all possible.

Is there a good way to make any calls using LWP::UserAgent utilize a proxy server _without_ modifying the perl source?

Thanks!

Chris

In reply to Chris Ahrendt

Re: Student answer submissions take extremely long to process after upgrade to 2.17

by Chris Ahrendt -
Hey all~

We got this working, and so here is the info in case it is useful for anyone. The summarize the situation: our WebWork server requires the use of a proxy for http & https access. The typical Ubuntu environment variables that most commands rely on for the proxy seem to have no affect on LWP::UserAgent which is used in the LTIAdvanced authentication in order to passback grades to the LMS. In particular, when LWP::UserAgent was invoked in SubmitAnswers.pm it would fail after a timeout.

We got it working by modifying lib/WeBWorK/Authen/LTIAdvanced/SubmitGrade.pm in the two places that LWP::UserAgent is invoked.  We just added a line to set the proxy server info:

diff --git a/lib/WeBWorK/Authen/LTIAdvanced/SubmitGrade.pm b/lib/WeBWorK/Authen/LTIAdvanced/SubmitGrade.pm
index 4fd71a8a8..0f2af1d64 100644
--- a/lib/WeBWorK/Authen/LTIAdvanced/SubmitGrade.pm
+++ b/lib/WeBWorK/Authen/LTIAdvanced/SubmitGrade.pm
@@ -324,7 +324,11 @@ EOS
               $readResultXML,
                                      );
 
-    $response = LWP::UserAgent->new->request($HTTPRequest);
+    my $ua = LWP::UserAgent->new;
+    $ua->proxy(['http', 'https', 'ftp'], 'http://[proxy server]:[port]/');
+    $response = $ua->request($HTTPRequest);
+    #$response = LWP::UserAgent->new->request($HTTPRequest);
 
     # debug section
     if ($ce->{debug_lti_grade_passback} and $ce->{debug_lti_parameters}){
@@ -458,9 +462,14 @@ EOS
                );
     debug ("posting grade request: $HTTPRequest");
 
-    $response = eval {
-      LWP::UserAgent->new->request($HTTPRequest);
-    };
+    my $ua = LWP::UserAgent->new;
+    $ua->proxy(['http', 'https', 'ftp'], 'http://[proxy server]:[port]/');
+    $response = eval { $ua->request($HTTPRequest); };
+
+    #$response = eval {
+    #  LWP::UserAgent->new->request($HTTPRequest);
+    #};
     if ($@) {
       warn "error sending HTTP request to LMS, $@";
     }

A quick search of the webwork2 repository indicates that this is the only place that LWS::UserAgent is used.  Perhaps this could be incorporated using a setting in localOverrides.pm?

Thanks for all the help in diagnosing the issue!

Chris
In reply to Chris Ahrendt

Re: Student answer submissions take extremely long to process after upgrade to 2.17

by Danny Glin -
This looks like something that could be useful if other people need to use proxy servers.

Are you able to create a pull request to the WeBWorK repository on GitHub?
In reply to Chris Ahrendt

Re: Student answer submissions take extremely long to process after upgrade to 2.17

by Nathan Wallach -
I can try to prepare a suitable pull request, but will need some help to test the code - as I don't have a http proxy server to test with.

I would say that we should add a new LTI setting $LTI_http_proxy to accept the entire "proxy value" (what was denoted as http://[proxy server]:[port]/ above), and modify the file so that when it is set the approach above will be used.

From what I found at https://metacpan.org/dist/libwww-perl/view/lwpcook.pod  if the proxy requires a password a setting like http://[user:password@proxy server]:[port]/ is supposed to work.

Is there a potential need to set a different proxy setting for http and https here? (If so, two settings will be needed.)

Since I do not think the LTI code would ever use a ftp request, so I think that there is any reason to provide a setting for ftp.