Installation

/webwork2/instructorXMLHandler: timeout

/webwork2/instructorXMLHandler: timeout

by Chris Caldwell -
Number of replies: 17
We just upgraded WeBWorK (Ubuntu 14.04.5 LTS; Apache/2.4.7;v5.18.2; perl 5.18.2) and most things work fine (viewing grades, copy homework sets to other courses, assign & work problems, check answers, re-set due dates, send mail, ...) but we cannot add new problems. The Library browser pops up nicely with "35102 matching WeBWorK problems" but if we select a problem set or a subject we get a little message box saying

math.utm.edu says:
/webwork2/instructorXMLHandler: timeout

The web server error log has

[Wed Aug 02 18:44:45.606117 2017] [perl:warn] [pid 13719] [client 10.10.5.9:57646] [/webwork2/instructorXMLHandler] Use of uninitialized value in join or string at /opt/webwork/webwork2/lib/WebworkClient.pm line 292., referer: http://math.utm.edu/webwork2/MATH140_FALL_17_CALDWELL/instructor/setmaker/?

repeated many times (that print command usually commented out, I uncommented it in the source hoping for more info) followed eventually by

WebworkClient: issue command WebworkXMLRPC.searchLib library_subjects Algebra version_last_attempt_time command getAllDBchapters version_time_limit user caldwell envir HASH(0x7f4f7025b4f0) set_id time_interval probList time_limit_cap student_id path id source processAnswers 1 hide_score last_name maxdepth 0 library_chapters course_password library_name Library library_status place assigned_users library_textbook new_password pgCode noprepostambles attempts_per_version due_date hide_work library_sections userID caldwell library_textsection enable_reduced_scoring 0 var answer_date value displayMode restricted_login_proctor first_name sendViaJSON restrict_ip section set_header answer_form_submitted 1 version_creation_time relax_restrict_ip problems_per_page hide_score_by_problem library_keywords subcommand set_props email_address showHints 0 permission 0 selfassign problem_state HASH(0x7f4f71d3c910) library_textchapter fileName set set0 hardcopy_header courseID MATH140_FALL_17_CALDWELL new_set_name new set showSolutions 0 assignment_type status mode images versions_per_interval session_key XsJzAq3S77wcLrSrTOmbzfaH1wSN29ph userpassword visible 0 users overrides library_levels comment recitation problem_randorder open_date problemSeed 0

There were a lot of errors

Errors:

500 Can't connect to math.utm.edu:80 (Connection timed out) at /opt/webwork/webwork2/lib/WebworkClient.pm line 293.

End Errors

xmlrpcCall to searchLib returned no result for

[Wed Aug 02 18:46:52.910072 2017] [perl:error] [pid 13719] [client 10.10.5.9:57646] [/webwork2/instructorXMLHandler] xmlrpcCall to searchLib returned no result for \n * in WeBWorK::ContentGenerator::instructorXMLHandler::content called at line 232 of /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator.pm\n * in WeBWorK::ContentGenerator::go called at line 384 of /opt/webwork/webwork2/lib/WeBWorK.pm, referer: http://math.utm.edu/webwork2/MATH140_FALL_17_CALDWELL/instructor/setmaker/?key=XsJzAq3S77wcLrSrTOmbzfaH1wSN29ph&user=caldwell&effectiveUser=caldwell

I carefully scanned the conf files, we updated the courses, restarted the server, ...

Any clues what to try next?
In reply to Chris Caldwell

Re: /webwork2/instructorXMLHandler: timeout

by Michael Gage -
Usually this means that the site url in site.conf has not been defined correctly.
$server_root_url = "https://mysite.edu";
This has to be exactly the url that reaches the server (e.g. https and http are not interchangeable). Browsers often try alternatives or fallow redirects if the initial url fails to connect, but the call back functions do not. They fail immediately unless the url is exactly correct.

Bringing up the Developer->Developer Tools window in chrome will allow you to watch the traffic back to the server and you may see which calls are failing to connect and the url they are trying to connect to.

Good luck. Report back when you find the fix.
In reply to Michael Gage

Re: /webwork2/instructorXMLHandler: timeout

by Chris Caldwell -
They seem to match. site.conf has

$webwork_url = '/webwork2';
$server_root_url = 'http://math.utm.edu';

Chrome reports that ts fails to load

http://math.utm.edu/webwork2/instructorXMLHandler

(POST, (canceled), xhr, jquery.js:4, 0B, 12.10 sec). Is there something wrong there?

In reply to Chris Caldwell

Re: /webwork2/instructorXMLHandler: timeout

by Michael Gage -
Typing http://hosted2.webwork.rochester.edu/webwork2/instructorXMLHandler
into the browser gives me a bunch of error messages.

WeBWorK error

An error occured while processing your request. For help, please send mail to this site's webmaster (gage@math.rochester.edu), including all of the following information as well as what what you were doing when the error occured.

Thu Aug 03 10:18:59 2017

Warning messages

  • Use of uninitialized value in anonymous hash ({}) at /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator/instructorXMLHandler.pm line 182. Use of uninitialized value in anonymous hash ({}) at /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator/instructorXMLHandler.pm line 182. Use of uninitialized value in anonymous hash ({}) at /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator/instructorXMLHandler.pm line 182. Use of uninitialized
etc. etc.

Typing http://math.utm.edu/webwork2/instructorXMLHandler into the browser

simply hangs. There may be an entry in your logs about some request timing out.


Perhaps the permissions for the file accessed by instructorXMLHandler (lib/WeBWorK/ContentGenerator/instructorXMLHandler.pm) doesn't allow the webserver to read it? The logs may give more detail.


In reply to Michael Gage

Re: /webwork2/instructorXMLHandler: timeout

by Chris Caldwell -
First, I really appreciate your help--I am really stuck and folks can't update their classes for Fall. This thing worked fine for years...

Note http://math.utm.edu/webwork2/instructorXMLHandler gives a list of errors that starts the same as yours, you just need to wait a full two minutes to see it. It ends with

xmlrpcCall to HASH(0x7f4f6f379d48) returned no result for

then the call stack... Looking in the server log I see the same message plus

There were a lot of errors
Errors:
500 Can't connect to math.utm.edu:80 (Connection timed out) at /opt/webwork/webwork2/lib/WebworkClient.pm line 293.

End Errors
[Thu Aug 03 10:01:06.542641 2017] [perl:error] [pid 28290] [client 10.10.5.7:65166] [/webwork2/instructorXMLHandler] xmlrpcCall to HASH(0x7f4f6f379d48) returned no result for \n * in WeBWorK::ContentGenerator::instructorXMLHandler::content called at line 232 of /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator.pm\n * in WeBWorK::ContentGenerator::go called at line 384 of /opt/webwork/webwork2/lib/WeBWorK.pm

Something is surely timing out--but what? I thought it could be file permissions too, so tried webwork2/bin/setfilepermissions yesterday with no joy.

Thank-you again--any more ideas?
In reply to Chris Caldwell

Re: /webwork2/instructorXMLHandler: timeout

by Danny Glin -
If this were a RedHat system, I would blame SElinux, but I don't think that exists in Ubuntu.

I ran into an issue before in that the Library Browser sends requests to the URL $server_root_url/mod_xmlrpc. If I connect to http://math.utm.edu/mod_xmlrpc, I get the same error as I do on my server or hosted2, which I believe means that something is listening on that URL. Is it possible that there is something else on your server that uses that same URL?
In reply to Danny Glin

Re: /webwork2/instructorXMLHandler: timeout

by Michael Gage -
Hi Chris,

It's time to start deeper debugging I guess since the random guesses aren't working. What instructorXMLHandler does is to take the request that is sent to it, repackages it and then sends it to the WeBWorK webservice listener (mod_xmlrpc). There is a variable $UNIT_TESTS_ON which is set to zero. Setting it to 1 will give some additional warning messages.

My first guess from the warning messages you are getting is that the POST request is not coming through properly. All of the $r->param() variables
seem to be empty. I'm not quite sure why this would be.

Do you have the same problem when using "render all" in a homework set? That uses a similar but not identical mechanism to the libraryBrowser.

The code is here
https://github.com/openwebwork/webwork2/blob/master/lib/WeBWorK/ContentGenerator/instructorXMLHandler.pm#L33

Most of the work translating from the HTML form to the webwork_client is done in the "preheader_initialize" function. The HTML returned by the webwork_client is printed back to the requesting agent in the "content" function.

Hope this helps.

-- Mike

In reply to Michael Gage

Re: /webwork2/instructorXMLHandler: timeout

by Michael Gage -
one last thing -- you can enable the librarybrowsernojs link in
localOverrides.conf. (uncomment this)

#$showeditors{librarybrowsernojs} = 1;

That gives you access to an older version of the library browser that does not
use AJAX commands. It may allow faculty to get some work done while you
are researching the fix for the AJAX callback.


In reply to Michael Gage

Re: /webwork2/instructorXMLHandler: timeout

by Chris Caldwell -
Thank-you. I discovered this a couple hours ago reading conf files again and was greatly relieved that we had a working system. Thank-you for posting this anyway--it is a helpful note.
In reply to Michael Gage

Re: /webwork2/instructorXMLHandler: timeout

by Chris Caldwell -
Sounds like a good idea. Set the flag and restarted. The tried to select a set in a course to add problems too.
[Thu Aug 03 23:12:08.720358 2017] [mpm_prefork:notice] [pid 12747] AH00171: Graceful restart requested, doing restart
[Thu Aug 03 23:12:09.751966 2017] [ssl:warn] [pid 12747] AH02292: Init: Name-based SSL virtual hosts only work for clients with TLS server name indication support (RFC 4366)
[Thu Aug 03 23:12:09.752160 2017] [mpm_prefork:notice] [pid 12747] AH00163: Apache/2.4.7 (Ubuntu) OpenSSL/1.0.1f mod_apreq2-20090110/2.8.0 mod_perl/2.0.8 Perl/v5.18.2 configured -- resuming normal operations
[Thu Aug 03 23:12:09.752167 2017] [core:notice] [pid 12747] AH00094: Command line: '/usr/sbin/apache2'
instructorXMLHandler.pm 268 values obtained from form parameters
answer_date=>-- assigned_users=>-- assignment_type=>-- attempts_per_version=>--
command=>true comment=>-- courseID=>MATH140_FALL_17_CALDWELL displayMode=>--
due_date=>-- email_address=>-- enable_reduced_scoring=>0 fileName=>--
first_name=>-- hardcopy_header=>-- hide_score=>-- hide_score_by_problem=>--
hide_work=>-- id=>-- last_name=>-- library_chapters=>--
library_keywords=>-- library_levels=>-- library_name=>Library library_sections=>--
library_status=>-- library_subjects=>-- library_textbook=>-- library_textchapter=>--
library_textsection=>-- maxdepth=>0 new_password=>-- new_set_name=>new set
noprepostambles=>-- open_date=>-- overrides=>-- path=>--
permission=>0 pgCode=>-- place=>-- probList=>--
problemSeed=>0 problem_randorder=>-- problems_per_page=>-- processAnswers=>1
recitation=>-- relax_restrict_ip=>-- restrict_ip=>-- restricted_login_proctor=>--
section=>-- selfassign=>-- sendViaJSON=>-- session_key=>ejgKZQfvXHsup2buhUvuFzh17EKgCZlo
set=>set0 set_header=>-- set_id=>test set_props=>--
showHints=>0 showSolutions=>0 source=> status=>--
student_id=>-- subcommand=>-- time_interval=>-- time_limit_cap=>--
user=>caldwell userID=>caldwell userpassword=>-- users=>--
value=>-- var=>-- version_creation_time=>-- version_last_attempt_time=>--
version_time_limit=>-- versions_per_interval=>-- visible=>0

The above pops up right away in the error log, the error box appears on the browsers saying timed out, and maybe sixty seconds later the error log finishes the above entry as follows.

Errors:
500 Can't connect to math.utm.edu:80 (Connection timed out) at /opt/webwork/webwork2/lib/WebworkClient.pm line 293.

End Errors
xmlrpcCall to listSetProblems returned no result for
Use of uninitialized value in subroutine entry at /usr/local/share/perl/5.18.2/HTML/Scrubber.pm line 181.
[Thu Aug 03 23:14:55.599539 2017] [perl:error] [pid 15210] [client 10.10.5.2:51882] [/webwork2/instructorXMLHandler] xmlrpcCall to listSetProblems returned no result for \n * in WeBWorK::ContentGenerator::instructorXMLHandler::content called at line 232 of /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator.pm\n * in WeBWorK::ContentGenerator::go called at line 384 of /opt/webwork/webwork2/lib/WeBWorK.pm, referer: http://math.utm.edu/webwork2/MATH140_FALL_17_CALDWELL/instructor/setmaker/?key=ejgKZQfvXHsup2buhUvuFzh17EKgCZlo&user=caldwell&effectiveUser=caldwell

(I commented line 292 back out as it did not seem to say anything useful).

If by "render all" you mean "view problems," then it seems to work. The error comes when I select a problem set, select a chapter, or select a rendered problem to add. Thank-you again for all of this help.
In reply to Chris Caldwell

Re: /webwork2/instructorXMLHandler: timeout

by Michael Gage -
Hi,

I'm up against by deadline for packing for vacation so I will out of the loop for the next few weeks. Here are some thoughts:

1. I meant "render all" -- it's a tab in the HomeworkEditor, not the LibraryBrowser. The homework editor lists all of the problems in a set, displaying their paths. It doesn't usually display the contents of the problems but if you press "render all" then it calls back and produces rendered versions of the problem. It's a similar mechanism to one used by the LibraryBrowser.

2. Also try both MathJax and Image modes for displaying equations -- it should make no difference, but .....

3. The third line in your error messages above says something SSL. I don't quite understand that message, and I'm not sure it's an actual error since it's occurring during the restart of the server. But I've been looking for some kind of error where WW is trying to use ssl to connect and the server or client is not (or vice-versa)

Danny is helping and I think Jason Aubrey will be back from vacation soon.
Others may have some ideas.

Good luck.

In reply to Michael Gage

Re: /webwork2/instructorXMLHandler: timeout

by Danny Glin -
I'm not sure if this is related to the issue, but it looks like your server has SSL enabled, but for some reason webwork isn't showing up when you connect using https.

Navigating to http://math.utm.edu/webwork2/ leads to the ww landing page, while https://math.utm.edu/webwork2/ leads to a not found error.

If for some reason something in WeBWorK is trying to connect using https, it won't get anything back. It's possible that this is what's causing all of the variables to be empty.

This could be a red herring, since you have $server_root_url set to http and not https, so it should be crafting all urls based on that, but it's possible that something somewhere is defaulting to https, which is causing the problem.
In reply to Danny Glin

Re: /webwork2/instructorXMLHandler: timeout

by Chris Caldwell -
You are correct Danny, this server does have SSL enabled. I have no clue why https://math.utm.edu/webwork2 fails, I had guessed it was a "feature" of webwork that it would not show if I used "http://math.utm.edu" in the conf files. Should it show? The https call generates no error in the log when not found--that is odd to me Like many here I am a math prof, and an ametuer at running servers at best.
In reply to Michael Gage

Re: /webwork2/instructorXMLHandler: timeout

by Chris Caldwell -

Michael Gage >> 1. I meant "render all" -- it's a tab in the HomeworkEditor, not the LibraryBrowser. ...

Response >> The "render all" fails with a similar timeout (both images & MathJax) but does show a box for each problem with a path. If you click "automatically render problems on page load" then it also appears to render just fine (both images & MathJax). On this screen each problem has three icons: the render icon just seems to get lost (no error message, no rendering); the edit and open in a new window icons seems succeed (and the new window renders just fine). Here is an error message for the render icon.

instructorXMLHandler.pm 268 values obtained from form parameters

answer_date=>-- assigned_users=>-- assignment_type=>-- attempts_per_version=>-- command=>-- comment=>-- courseID=>MATH140_FALL_17_CALDWELL displayMode=>MathJax due_date=>-- email_address=>-- enable_reduced_scoring=>0 fileName=>-- first_name=>-- hardcopy_header=>-- hide_score=>-- hide_score_by_problem=>-- hide_work=>-- id=>-- last_name=>-- library_chapters=>-- library_keywords=>-- library_levels=>-- library_name=>-- library_sections=>-- library_status=>-- library_subjects=>-- library_textbook=>-- library_textchapter=>-- library_textsection=>-- maxdepth=>0 new_password=>-- new_set_name=>-- noprepostambles=>1 open_date=>-- overrides=>-- path=>-- permission=>0 pgCode=>-- place=>-- probList=>-- problemSeed=>1 problem_randorder=>-- problems_per_page=>-- processAnswers=>0 recitation=>-- relax_restrict_ip=>-- restrict_ip=>-- restricted_login_proctor=>-- section=>-- selfassign=>-- sendViaJSON=>-- session_key=>DfSkLMz1NgB62obGRuOC4M8jGhz0Ghte set=>Library/ma117DB/set1b/srw1_3_41.pg set_header=>-- set_id=>test set_props=>-- showHints=>1 showSolutions=>1 source=> status=>-- student_id=>-- subcommand=>-- time_interval=>-- time_limit_cap=>-- user=>caldwell userID=>caldwell userpassword=>-- users=>-- value=>-- var=>-- version_creation_time=>-- version_last_attempt_time=>-- version_time_limit=>-- versions_per_interval=>-- visible=>0

There were a lot of errors

Errors:

500 Can't connect to math.utm.edu:80 (Connection timed out) at /opt/webwork/webwork2/lib/WebworkClient.pm line 293.

End Errors

xmlrpcCall to renderProblem returned no result for

[Sat Aug 05 10:29:00.533012 2017] [perl:error] [pid 40423] [client 10.10.5.6:60561] [/webwork2/instructorXMLHandler] xmlrpcCall to renderProblem returned no result for \n * in WeBWorK::ContentGenerator::instructorXMLHandler::content called at line 232 of /opt/webwork/webwork2/lib/WeBWorK/ContentGenerator.pm\n * in WeBWorK::ContentGenerator::go called at line 384 of /opt/webwork/webwork2/lib/WeBWorK.pm, referer: http://math.utm.edu/webwork2/MATH140_FALL_17_CALDWELL/instructor/sets2/test/

Michael Gage >> 2. Also try both MathJax and Image modes for displaying equations -- it should make no difference, but .....

Response >> You are correct, it makes no difference—both work or both failed as noted before.

Michael Gage >> 3. The third line in your error messages above says something SSL. I don't quite understand that message, and I'm not sure it's an actual error since it's occurring during the restart of the server. But I've been looking for some kind of error where WW is trying to use ssl to connect and the server or client is not (or vice-versa)

Response >> Yes, it is a warning about the use of a virtual server which may effect calls using SNI. I fixed it (no change to WeBWorK). Here is the complete start up message. What strikes me is that everything form WeBWorK shows up twice. Is that normal?

caldwell@primes:/etc/apache2$ sudo apache2ctl graceful
[sudo] password for caldwell:
webwork.apache2-config: webwork_server_admin_email for reporting bugs has been set to caldwell@utm.edu in site.conf
webwork.apache2-config: WeBWorK server is starting
webwork.apache2-config: WeBWorK root directory set to /opt/webwork/webwork2 in webwork2/conf/webwork.apache2-config
webwork.apache2-config: The following locations and urls are set in webwork2/conf/site.conf
webwork.apache2-config: PG root directory set to /opt/webwork/pg
webwork.apache2-config: WeBWorK server userID is www-data
webwork.apache2-config: WeBWorK server groupID is wwdata
webwork.apache2-config: The webwork url on this site is http://math.utm.edu/webwork2
webwork.apache2-config: The webwork smtp server address is xmail.utm.edu
webwork.apache2-config: The webwork smtp server port is
webwork.apache2-config: The webwork smtp server protocol is 'not ssl'
WebworkSOAP::WSDL: webwork_directory set to /opt/webwork/webwork2 via $WeBWorK::Constants::WEBWORK_DIRECTORY set in webwork.apache2-config
WebworkSOAP::WSDL: rpc_url set to http://math.utm.edu/webwork2_rpc
WebworkWebservice: webwork_directory set to /opt/webwork/webwork2 via $WeBWorK::Constants::WEBWORK_DIRECTORY set in webwork.apache2-config
webwork.apache2-config: webwork_server_admin_email for reporting bugs has been set to caldwell@utm.edu in site.conf
webwork.apache2-config: WeBWorK server is starting
webwork.apache2-config: WeBWorK root directory set to /opt/webwork/webwork2 in webwork2/conf/webwork.apache2-config
webwork.apache2-config: The following locations and urls are set in webwork2/conf/site.conf
webwork.apache2-config: PG root directory set to /opt/webwork/pg
webwork.apache2-config: WeBWorK server userID is www-data
webwork.apache2-config: WeBWorK server groupID is wwdata
webwork.apache2-config: The webwork url on this site is http://math.utm.edu/webwork2
webwork.apache2-config: The webwork smtp server address is xmail.utm.edu
webwork.apache2-config: The webwork smtp server port is
webwork.apache2-config: The webwork smtp server protocol is 'not ssl'
WebworkSOAP::WSDL: webwork_directory set to /opt/webwork/webwork2 via $WeBWorK::Constants::WEBWORK_DIRECTORY set in webwork.apache2-config
WebworkSOAP::WSDL: rpc_url set to http://math.utm.edu/webwork2_rpc
WebworkWebservice: webwork_directory set to /opt/webwork/webwork2 via $WeBWorK::Constants::WEBWORK_DIRECTORY set in webwork.apache2-config

The conf file I am using is

/opt/webwork/webwork2/conf/webwork.apache2.4-config

which is included into the conf file for the virtual server math.utm.edu (which runs on primes.utm.edu). Have a great vacation Michael.
In reply to Chris Caldwell

Re: /webwork2/instructorXMLHandler: timeout

by Danny Glin -
It is odd that the WeBWorK messages show up twice when you start apache. Is it possible that you have included webwork.apache2.4-config in more than one place in your apache config?

If you used the WeBWorK installer to install WeBWorK, then it probably placed a symbolic link to webwork.apache2.4-config in the conf.d directory of your apache config (I'm not sure where this lives in Ubuntu. In CentOS it is /etc/httpd/conf.d). If you also included the config file in your virtual host config for math.utm.edu, then it will be reading the file twice, which may cause weird behaviour.

As for why WeBWorK doesn't show up when you use https, I don't think this is related to $server_root_url. As far as I know, that only affects the webservice components. The core WeBWorK web functionality is handled in webwork.apache2.4-config. More likely it is because you have separate virtual hosts set up for math.utm.edu:80 and math.utm.edu:443, and the WeBWorK config is only being read by the former.

If you're willing to post your full apache configuration, I can see if anything looks off to me.
In reply to Danny Glin

Re: /webwork2/instructorXMLHandler: timeout

by Chris Caldwell -

I am going to just drop this for now because the old library browser works and the semester is about to start. In a couple months I hope to set up another server with more current software--this alone could solve the problem.

Thank-you Michael and Danny, you have both been very helpful.

In reply to Chris Caldwell

Re: /webwork2/instructorXMLHandler: timeout

by Nathan Wallach -
The :

500 Can't connect to math.utm.edu:80 (Connection timed out) at /opt/webwork/webwork2/lib/WebworkClient.pm line 293.

seems to suggest a similar problem to the discussion about problems in Docker in http://webwork.maa.org/moodle/mod/forum/discuss.php?d=4173 so that thread may be related.

In that case, the "server" (the Docker container) did not know how to route traffic to itself, which caused the "500 Can't connect to ..." error.

Adding an extra record to /etc/hosts to make sure the machine can resolve its own FQDN (fully qualified domain name) without use of DNS may help.


(Edited by Michael Gage - original submission Wednesday, 21 November 2018, 12:48 PM)