Moodle Plugin "Upgrade Library Content" just spins saying "Upgrading to ..." but never does?

Submitted by AlexW on Tue, 10/11/2016 - 11:14
Forums: 
Installation and server related problems

Hi,

Thanks for all the work on H5P so far.

Can I clarify a few points:

1) H5P plugin on Moodle, recent update installed some new content types so in some cases have multiple versions e.g. :

Multiple Choice (1.7.1)132

Multiple Choice (1.8.0)011

Interactive Video (1.10.3)122

Interactive Video (1.11.1)111

Tried hitting "Upgrade Library Content" on both, it then goes to say for example "Upgrading to 1.11.1..." but then nothing happens?!?

2) Related is there an end user benefit to upgrading LIbrary Content or can multiple H5P content types of different version happily coexist? If a user created some H5P outside the Moodle installed editors and it was of a later version than installed content type and they then used "upload H5P" option would that content run? Would it by definition update the H5P Content type in question?

3) There is a "restricted" option when viewing all the installed libraries, presumably to disable that content type? However clicking on these does not work? Is it possible to remove a specific H5P content type?

Thanks,

Alex

 

 

 

 

thomasmars's picture

thomasmars

Wed, 10/12/2016 - 09:33

1) Can you open your browser console to see if there are any errors there ? Also check your server php log if this yields no results.

2) The end user benefit to upgrading libraries is that they get the latest fixes and features for the content types. Multiple versions of content types can indeed happily coexist. 

If content with a newer version is uploaded that version of the library is uploaded to your server and the content. Your old content will stay the old version, but you will be able to upgrade it if you choose so.

3) The restricted option is to disable creating the content type for normal users/authors/editors. An administrator, which presumably you are, would still be able to create the content types. If you really want to uninstall a content type you can do it in the H5P Library admin screen, though this is not possible if you have content or other libraries that are relying on the library you are trying to uninstall.

- Thomas

AlexW

Wed, 10/12/2016 - 10:50

Hi Thomas,

Thanks for getting back to me, much appreciated.

Re the fail to update content, yes console in browser shows:

http://moodle-test.warwick.ac.uk/mod/hvp/ajax.php?action=libraryupgradep... Failed to load resource: the server responded with a status of 500 (Internal Server Error)

Couple that could be relevant in server log:

[Wed Oct 12 09:19:18.058462 2016] [proxy_fcgi:error] [pid 2920:tid 140062826157824] [client 137.205.194.4:59951] malformed header from script 'ajax.php': Bad header: {"params":{"6":"{\\"media\\":{\\", referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

[Wed Oct 12 09:19:18.058560 2016] [proxy_fcgi:error] [pid 2920:tid 140062826157824] [client 137.205.194.4:59951] AH01070: Error parsing script headers, referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

Thanks,

Alex

 

icc's picture

icc

Thu, 10/13/2016 - 09:29

This error message is typical when the empty line between the HTTP headers and the content is missing. Now, as to why you're getting this error I'm a bit puzzled. If you look at the H5P code it lets PHP handle this the standard way, which leads me to be leave that there may be something misconfigured somewhere – A special plugin or config inserting extra headers or something of that sort.

Do you know if you get this error message anywhere else? Very strange if it's only the upgrade process…

AlexW

Thu, 10/13/2016 - 16:25

Hi,

I checked the errorlog and in the 2200 lines there were 11 Bad Header errors all about /mod/hvp/library_list.php or /mod/hvp/upgrade_content_page.php , no other issues with that Moodle environment that im aware of. Any ideas?

Thanks,

Alex

AlexW

Thu, 10/13/2016 - 16:28

Below for reference: \moodle\error_log (11 hits)

Line 331: [Tue Oct 11 09:44:41.840612 2016] [proxy_fcgi:error] [pid 3114:tid 140062750623488] [client 137.205.194.4:60079] malformed header from script 'ajax.php': Bad header: {"params":{"5":"{\\"interactive, referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

Line 334: [Tue Oct 11 09:52:26.416158 2016] [proxy_fcgi:error] [pid 2920:tid 140062792587008] [client 137.205.194.4:60187] malformed header from script 'ajax.php': Bad header: {"url":"http:\\/\\/moodle-test.w, referer: http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php

Line 336: [Tue Oct 11 09:52:28.738614 2016] [proxy_fcgi:error] [pid 2919:tid 140062817765120] [client 137.205.194.4:60189] malformed header from script 'ajax.php': Bad header: {"url":"http:\\/\\/moodle-test.w, referer: http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php

Line 339: [Tue Oct 11 09:53:11.194954 2016] [proxy_fcgi:error] [pid 2919:tid 140062809372416] [client 137.205.194.4:60195] malformed header from script 'ajax.php': Bad header: {"params":{"6":"{\\"media\\":{\\", referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

Line 342: [Tue Oct 11 09:54:45.944034 2016] [proxy_fcgi:error] [pid 3114:tid 140062767408896] [client 137.205.194.4:60249] malformed header from script 'ajax.php': Bad header: {"params":{"6":"{\\"media\\":{\\", referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

Line 346: [Tue Oct 11 10:02:11.855216 2016] [proxy_fcgi:error] [pid 2919:tid 140062767408896] [client 137.205.194.4:60371] malformed header from script 'ajax.php': Bad header: {"params":{"5":"{\\"interactive, referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

Line 348: [Tue Oct 11 10:07:25.589967 2016] [proxy_fcgi:error] [pid 2919:tid 140062742230784] [client 137.205.194.4:60379] malformed header from script 'ajax.php': Bad header: {"url":"http:\\/\\/moodle-test.w, referer: http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php

Line 350: [Tue Oct 11 10:07:26.809194 2016] [proxy_fcgi:error] [pid 2919:tid 140062725445376] [client 137.205.194.4:60383] malformed header from script 'ajax.php': Bad header: {"url":"http:\\/\\/moodle-test.w, referer: http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php

Line 352: [Tue Oct 11 10:07:30.894181 2016] [proxy_fcgi:error] [pid 2920:tid 140062742230784] [client 137.205.194.4:60400] malformed header from script 'ajax.php': Bad header: {"url":"http:\\/\\/moodle-test.w, referer: http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php

Line 1222: [Wed Oct 12 09:19:18.058462 2016] [proxy_fcgi:error] [pid 2920:tid 140062826157824] [client 137.205.194.4:59951] malformed header from script 'ajax.php': Bad header: {"params":{"6":"{\\"media\\":{\\", referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

Line 1231: [Wed Oct 12 09:49:01.763161 2016] [proxy_fcgi:error] [pid 3114:tid 140062759016192] [client 137.205.194.4:60303] malformed header from script 'ajax.php': Bad header: {"url":"http:\\/\\/moodle-test.w, referer: http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php

icc's picture

icc

Fri, 10/14/2016 - 11:29

Ok, it seems some of the other AJAX requests are failing as well. We could try to debug this by looking at the requests in the browser. If you first open the developer tools by pressing Ctrl + Shift + J in

If you first open the developer tools by pressing Ctrl + Shift + J in Chrome, and then click on the Network tab – select the filter named XHR next to 'JS CSS Img' etc.. This should allow you to view all the AJAX requests. Navigate to the /mod/hvp/library_list.php URL of your Moodle install. Now if you check or uncheck the 'restrict' checkbox for one of the content types you should start to see requests in the network tab. Right click one of the requests and copy the request headers, response headers and response content if available. Paste the results here and we'll have a look.

Alternatively, if you prefer you can send me the username and password and I'll have a look for you. My email is: frode.petterson (at) joubel.com.

Another thing you could try is to modify the /mod/hvp/ajax.php file by adding the following:

echo "\n";

Between the header() and echo on lines 75 and 76, like this:

header('Content-Type: application/json');
echo "\n";
echo json_encode(array(

and then clicking the restrict checkbox again to see if it still fails.

Which web server and PHP version is your Moodle site running on?

I really hope we'll be able to figure out what causes this issue.

AlexW

Fri, 10/14/2016 - 16:19

Hi,

Thanks for getting back to me.

1) OK, re the developer mode XHR debug thats belows under 1a, throws a 500 error.

Also tried library upgrade, same thing, 1b below

2) I added echo "\n"; in at line 75 on ajax.php,went Developer Mode > Purge All Caches 

Went back into Library list and hit restrict, same outcome, 2 below

BTW its running on Apache/2.4.6 (CentOS) OpenSSL/1.0.1e-fips PHP Version 5.4.16

Had a quick look at the error log around the time of doing this, which is directly below.

Thanks,

Alex

[Fri Oct 14 14:58:59.271531 2016] [proxy_fcgi:error] [pid 2918:tid 140062800979712] [client 137.205.194.4:65336] malformed header from script 'ajax.php': Bad header: {"url":"http:\\/\\/moodle-test.w, referer: http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php

 

[Fri Oct 14 14:58:59.271603 2016] [proxy_fcgi:error] [pid 2918:tid 140062800979712] [client 137.205.194.4:65336] AH01070: Error parsing script headers, referer: http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php

[Fri Oct 14 15:02:02.898064 2016] [proxy_fcgi:error] [pid 3114:tid 140062700267264] [client 137.205.194.4:65415] malformed header from script 'ajax.php': Bad header: {"params":{"5":"{\\"interactive, referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

[Fri Oct 14 15:02:02.898127 2016] [proxy_fcgi:error] [pid 3114:tid 140062700267264] [client 137.205.194.4:65415] AH01070: Error parsing script headers, referer: http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...

 

 

1a) 

    1. Request URL:http://moodle-test.warwick.ac.uk/mod/hvp/ajax.php?action=restrict_librar...
    2. Request Method:GET
    3. Status Code: 500 Internal Server Error
    4. Remote Address:137.205.160.154:80
  1. Response Headersview source
    1. Connection:close
    2. Content-Length:0
    3. Content-Type:text/plain; charset=UTF-8
    4. Date:Fri, 14 Oct 2016 13:58:59 GMT
    5. Server:Apache/2.4.6 (CentOS) OpenSSL/1.0.1e-fips
  2. Request Headersview source
    1. Accept:application/json, text/javascript, */*; q=0.01
    2. Accept-Encoding:gzip, deflate, sdch
    3. Accept-Language:en-GB,en-US;q=0.8,en;q=0.6
    4. Connection:keep-alive
    5. Cookie:_ga=GA1.3.1448620309.1475832609; WarwickSSO=bnebexaocnnpqfnxewtwyrirbkpkqscgmpxdebfcbhbfheptno; SSO-LTC=wppxfpwedspjxniwrdunucmtutxpgywbbmatenbqqtqfwtqyox; _shibsession_64656661756c7468747470733a2f2f656c676f642e6c6e782e7761727769636b2e61632e756b2f73686962626f6c657468=_2290186dec6c6727976905c6883b01c0; MoodleSession=b5to409n13a4t0jpm16mkf6040
    6. Host:moodle-test.warwick.ac.uk
    7. Referer:http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php
    8. User-Agent:Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.143 Safari/537.36
    9. X-Requested-With:XMLHttpRequest
  3. Query String Parametersview sourceview URL encoded
    1. action:restrict_library
    2. token:a23a014cd16ba
    3. restrict:1
    4. library_id:9
    5. _:1476453531523
  4. 1b)
    1. Request URL:http://moodle-test.warwick.ac.uk/mod/hvp/ajax.php?action=libraryupgradep...
    2. Request Method:POST
    3. Status Code: 500 Internal Server Error
    4. Remote Address:137.205.160.154:80
  5. Response Headersview source
    1. Connection:close
    2. Content-Length:0
    3. Content-Type:text/plain; charset=UTF-8
    4. Date:Fri, 14 Oct 2016 14:02:02 GMT
    5. Server:Apache/2.4.6 (CentOS) OpenSSL/1.0.1e-fips
  6. Request Headersview source
    1. Accept:*/*
    2. Accept-Encoding:gzip, deflate
    3. Accept-Language:en-GB,en-US;q=0.8,en;q=0.6
    4. Connection:keep-alive
    5. Content-Length:32
    6. Content-Type:application/x-www-form-urlencoded; charset=UTF-8
    7. Cookie:_ga=GA1.3.1448620309.1475832609; WarwickSSO=bnebexaocnnpqfnxewtwyrirbkpkqscgmpxdebfcbhbfheptno; SSO-LTC=wppxfpwedspjxniwrdunucmtutxpgywbbmatenbqqtqfwtqyox; _shibsession_64656661756c7468747470733a2f2f656c676f642e6c6e782e7761727769636b2e61632e756b2f73686962626f6c657468=_2290186dec6c6727976905c6883b01c0; MoodleSession=b5to409n13a4t0jpm16mkf6040
    8. Host:moodle-test.warwick.ac.uk
    9. Origin:http://moodle-test.warwick.ac.uk
    10. Referer:http://moodle-test.warwick.ac.uk/mod/hvp/upgrade_content_page.php?librar...
    11. User-Agent:Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.143 Safari/537.36
    12. X-Requested-With:XMLHttpRequest
  7. Query String Parametersview sourceview URL encoded
    1. action:libraryupgradeprogress
    2. library_id:55
  8. Form Dataview sourceview URL encoded
    1. libraryId:92
    2. token:2ac449a353806

2) 

    1. Request URL:http://moodle-test.warwick.ac.uk/mod/hvp/ajax.php?action=restrict_librar...
    2. Request Method:GET
    3. Status Code: 500 Internal Server Error
    4. Remote Address:137.205.160.154:80
  1. Response Headersview source
    1. Connection:close
    2. Content-Length:0
    3. Content-Type:text/plain; charset=UTF-8
    4. Date:Fri, 14 Oct 2016 14:06:56 GMT
    5. Server:Apache/2.4.6 (CentOS) OpenSSL/1.0.1e-fips
  2. Request Headersview source
    1. Accept:application/json, text/javascript, */*; q=0.01
    2. Accept-Encoding:gzip, deflate, sdch
    3. Accept-Language:en-GB,en-US;q=0.8,en;q=0.6
    4. Connection:keep-alive
    5. Cookie:_ga=GA1.3.1448620309.1475832609; WarwickSSO=bnebexaocnnpqfnxewtwyrirbkpkqscgmpxdebfcbhbfheptno; SSO-LTC=wppxfpwedspjxniwrdunucmtutxpgywbbmatenbqqtqfwtqyox; _shibsession_64656661756c7468747470733a2f2f656c676f642e6c6e782e7761727769636b2e61632e756b2f73686962626f6c657468=_2290186dec6c6727976905c6883b01c0; MoodleSession=b5to409n13a4t0jpm16mkf6040
    6. Host:moodle-test.warwick.ac.uk
    7. Referer:http://moodle-test.warwick.ac.uk/mod/hvp/library_list.php
    8. User-Agent:Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.143 Safari/537.36
    9. X-Requested-With:XMLHttpRequest
  3. Query String Parametersview sourceview URL encoded
    1. action:restrict_library
    2. token:5847a9176246b
    3. restrict:1
    4. library_id:14
    5. _:1476454010448
icc's picture

icc

Mon, 10/17/2016 - 09:47

Unfortunately, I'm unable to see what is causing these issues. The strange thing is that it's only the AJAX requests breaking.

Since this is working fine in other productions environments I'm guessing that the issues are related to the configuration, setup or version of the web server + PHP. I suggest trying to run Moodle in a different environment or upgrading to a newer version of Apache and PHP. I see that support for the version of PHP you're running ended over a year ago: https://secure.php.net/supported-versions.php

I'm sorry that I'm not able to be of any more help.

AlexW

Tue, 10/18/2016 - 15:48

Hi,

Thanks for the help thus far. I persuaded our server guys to upgrade PHP on that test server so now 5.6.5, however the same problem persists.

It could be some peculiarity of our customised theme I suppose, however strange it only manifests in these 2 operations i.e. H5P library restrict or H5P upgrade, and we cant deploy to a live environment until its resolved. I had thought could be persmissions issue writing to something in the hvp/libraries folder but manually added 777 and made no difference, any other avenues to try?

Thanks,

Alex

AlexW

Tue, 10/18/2016 - 17:41

I have resolved this, I isolated different aspects of ajax.php until it threw the 500 error, the line causing the issue was any instance of:

header('Cache-Control', 'no-cache');

changing this to:

header("Cache-Control: no-cache, must-revalidate");

or even

header("Cache-Control: no-cache");

resolves it and now both restrict and content update are working :-)

Still slightly unsure why, checked http version of the vm where it always worked and test platform which had the issue and both 1.1 i.e.

[admin@elgod /]$ curl --head www.test.com

HTTP/1.1 302 Moved Temporarily

Server: nginx/1.11.3

Date: Tue, 18 Oct 2016 15:35:43 GMT

Content-Type: text/html

Content-Length: 161

Connection: keep-alive

Keep-Alive: timeout=20

Location: https://www.test.com/

Thanks,

Alex

AlexW

Tue, 10/18/2016 - 17:57

Missing colon maybe as (note the colon after Control) 

header('Cache-Control:', 'no-cache');

works but 

header('Cache-Control', 'no-cache');

doesnt.

thomasmars's picture

thomasmars

Wed, 10/19/2016 - 08:15

Thanks a lot Alex, I will look into changing this for the plugin.

icc's picture

icc

Wed, 10/19/2016 - 08:58

You are indeed correct, there should be no comma inside the header() – only a single string. Not sure where this has come from but we'll have to fix all instances of this. It should look like this:

header('Cache-Control: no-cache');
header('Content-Type: application/json');

I'm happy to see that you finally found the culprit of this issue! Thank you for reporting so we can get this fixed for all. 

AlexW

Wed, 10/19/2016 - 10:09

No worries, do you need an address for my free H5P t-shirt?!? ;-) :-) :-)

icc's picture

icc

Wed, 10/19/2016 - 11:14

Yes, just send me your preferred size and address to frode . petterson (at) joubel . com (without the spaces)

dlader

Wed, 12/07/2016 - 15:51

I have the same issue of the system saying "upgrading" but just spinning and nothing happening.  This is a Moodle site.  PHP version is 5.6.  The only button showing in Actions is the upgrade button.  I have checked the code for the headers and it is correct.  Any suggestions on where to check to narrow down the issue?

AlexW

Wed, 12/07/2016 - 16:05

Dlader, are you using latest build of the Moodle plugin i.e. 2016113000? Also anything in the console output (F12 -> Console in Chrome) or Apache logs?

dlader

Wed, 12/07/2016 - 16:18

I am using the current Moodle plugin.  I am using the latest H5P library.  I am receiving the following errors in the Chrome Console.

Uncaught Error: Syntax error, unrecognized expression: #
    at Function.ga.error (http://nhlaw.com/lib/javascript.php/1481118009/lib/jquery/jquery-3.1.0.m...)
    at ga.tokenize (http://nhlaw.com/lib/javascript.php/1481118009/lib/jquery/jquery-3.1.0.m...)
    at ga.select (http://nhlaw.com/lib/javascript.php/1481118009/lib/jquery/jquery-3.1.0.m...)
    at Function.ga [as find] (http://nhlaw.com/lib/javascript.php/1481118009/lib/jquery/jquery-3.1.0.m...)
    at r.fn.init.find (http://nhlaw.com/lib/javascript.php/1481118009/lib/jquery/jquery-3.1.0.m...)
    at r.fn.init (http://nhlaw.com/lib/javascript.php/1481118009/lib/jquery/jquery-3.1.0.m...)
    at r (http://nhlaw.com/lib/javascript.php/1481118009/lib/jquery/jquery-3.1.0.m...)
    at c (http://nhlaw.com/lib/requirejs.php/1481118009/core/first.js:174:332)
    at HTMLAnchorElement.<anonymous> (http://nhlaw.com/lib/requirejs.php/1481118009/core/first.js:174:138)
    at Function.each (http://nhlaw.com/lib/javascript.php/1481118009/lib/jquery/jquery-3.1.0.m...)
http://nhlaw.com/mod/hvp/ajax.php?action=libraryupgradeprogress&library_... Failed to load resource: the server responded with a status of 405 (Method Not Allowed)

icc's picture

icc

Thu, 12/08/2016 - 14:35

Do you get this error on other pages as well or only when doing upgrades? If you get it on other sites as well the issue isn't really with H5P. 

If the error isn't present on any other pages it could mean that H5P isn't capable of running side-by-side with the newest jQuery. It looks almost as the built-in jQuery is trying to handle the AJAX request that H5P.jQuery is running.

Could you have a look in the network tab of the debugger and select the 'XHR' filter? This might give us an idea of which requests are failing.
It could even have something to do with the server setup since it's a 405 (Method Not Allowed).

 

icc's picture

icc

Thu, 12/08/2016 - 14:43

Hm, no actually it seems like the error happens inside the built-in jQuery. It's trying to find an invalid selector. It's difficult to see what's causing the error without visiting the site myself and looking at in the debugger.

I'm guessing that the crash happens before the H5P upgrade – which means that the H5P plugin code never gets to run.

dlader

Thu, 12/08/2016 - 20:23

This is the only error I am now receiving when I attempt the upgrade.

jquery.js?ver=2016113000:4 POST http://nhlaw.com/mod/hvp/ajax.php?action=libraryupgradeprogress&library_... 405 (Method Not Allowed)

If access to my site would help, please send a private email so I may give you credentials.

icc's picture

icc

Fri, 12/09/2016 - 11:42

Thanks, I've sent you an email.

I will post an update here when we've figured out the issue.

icc's picture

icc

Fri, 12/09/2016 - 15:27

I did some debugging and found out that this was, in fact, an issue with the implementation of the AJAX endpoint for the library upgrade process in the H5P plugin. I've created a fix for it here: 0557471

It's related to a known bug which exists in some builds of FCGI/PHP(5.4 and some older versions as well): https://bugs.php.net/bug.php?id=49184

 

The fix will be released with the next version of the plugin. If you would like to get the fix straight away you can simply replace line 136 of mod/hvp/ajax.php with the following:

if ($_SERVER['REQUEST_METHOD'] === 'POST') {