Moodle Upgrade and restoring courses

Re: Moodle Upgrade and restoring courses

by curt bixel -
Number of replies: 0

Note:  None of the servers indicated in the error logs below remain in existence and any passwords shown were unique to that server, so posting these should not be a security issue. 

 

Difficulties restoring courses.

 

This was a long walk through the park, and in the end, the solution was to simply add server capability.  There may have been other ways to solve the problems, as I never quite figured out what the problem was.  Here is a short version of what I suspect was happening:

 

The setup:

·            I set up a new server at Cloudways with 2GB ram.  (This has been enough to run my small site even with 25 students banging away at a quiz)

·            Moodle 2.9 was installed automatically (by something similar to Softaculous)

·            Small courses would restore and work properly.

·            Backup files for my 3 courses were uploaded to repository using ftp

 

The problem:

·            A large course (350MB) would not restore properly on my server.  (It would, however, restore properly on Ken Task’s server running 2.9 and 16GB ram)

o   The restore seemed to stall during the “process” step of restoration.  (Often the progress bar would show less then 1% finished, would be greyed out, and a ridiculous number of seconds would be displayed.  eg 26,755 seconds)

o   I tried restoring multiple times.

§  Upon inspecting the course after each restore, there were a variety of issues.

·            Issue 1 – out of 36 “weeks” sometimes a few would show as restored, often, none would have been restored.

·            Images were missing in quiz questions.  (Some images made it through, but when I inspected the HTML for those questions, instead of a link, it showed pages and pages of stuff like this: vp08q3etnmviadukm23[ c,mcv,mq[0eti90m43qo[  etc. )

·            Many hyperlinks still pointed to my old server, and thus either did not work, or opened a new page to my old server.

·            The course would restore properly if the question bank was excluded.  (I have 2500 questions, many with one or more images.) 

 

 

Things tried that did not solve the problem:

·            I suspected the process was timing out somehow, so I changed the server settings I know might be limiting the server.

§  Execution Limit = 99999 seconds

§  Upload size = 99999

§  Memory limit = 512 MB

§  Maximum input variables = 25,000

§  Maximum input time = 60000 seconds

§  APC Memory = 60 MB

·            I even tried making a new server with 16GB of memory, making the changes above, and restoring.  (I may, however, have forgotten to change the maximum input time with this attempt.

 

How I eventually solved the problem:

·            I made another new server with 48GB of RAM and 16 cores and had moodle 2.9 installed automatically.

·            I changed the server settings again as above.

·            The course restored successfully, and all problems were solved.

o   All content restored

o   All quiz images present

o   All hyperlinks pointed correctly to items on new site.

·            I then cloned the server back to 2GB, ( I can’t afford 48GB), and everything works perfectly.

 

What I suspect the problem may have been:

Restoring on 48 GB server seems to have made all the problems go away.  This does not, however, make me feel confident that I ever really was able to pinpoint the actual problem.  Here is my best guess:

 

I suspect the moodle restore process has many steps, and something was interrupting the restore process before all the steps were completed. 

Possible things that could have interrupted the process:

1.     Some setting at Cloudways designed to interrupt processes that took to many server resources.  ( I don’t think this was the problem, as I looked into this issue with technical support.  Furthermore, the course, for some reason I cannot fathom, managed to restore on my old server of 2GB, running 2.7, when Ken Task backed up my course in 2.9 on his server. )

2.     Some setting on my server that I do not have access to via the convenient user interface.

3.     Some server setting that I do have access to, but do not understand.

4.     Perhaps, it was I who was interrupting the process through lack of patience, although I did let the process run overnight several times with no improvement.

5.      

Whatever was interrupting the process, I believe it was interrupting the process before all the restore processes were completed, and I think that moodle attends to the links that support both hyperlinks and the links to images in the questions as one of the last steps in the restore process.  

 

When I moved to 48GB and 16 cores, the process likely completed before anything timed out and the course seems to work perfectly.  Go figure…..

 

Here are some nice error messages from logs and such that I found during the process:

 

Screen shot of progress bar:

 

 

Attempt that Failed.

Here is the screen shot of where it got stuck.  (Often at this point, it will display a ridiculous amount of time for the restore, such as 23,487 seconds.)

 

 

 

 

 

 

 

 

 

 

Questions have restored, but most of the images are missing.

The activites, files, and folders did not restore.  I have just a series of blank “Topics”.

The theme has not been set.

 

Here is the entirety of the error log for this server which has existed for less than 4 hours. 

 

[Mon Jun 15 10:13:48 2015] [error] [client 88.53.109.186] File does not exist: /home/13703-18176.cloudwaysapps.com/dgnmhgnreg/public_html/manager

[Mon Jun 15 12:26:48 2015] [error] [client 69.58.178.56] File does not exist: /home/13703-18176.cloudwaysapps.com/dgnmhgnreg/public_html/robots.txt

[Mon Jun 15 13:14:32 2015] [error] [client 182.254.129.24] File does not exist: /home/13703-18176.cloudwaysapps.com/dgnmhgnreg/public_html/phpMyAdmin

[Mon Jun 15 13:14:35 2015] [error] [client 182.254.129.24] File does not exist: /home/13703-18176.cloudwaysapps.com/dgnmhgnreg/public_html/pma

[Mon Jun 15 13:14:39 2015] [error] [client 182.254.129.24] File does not exist: /home/13703-18176.cloudwaysapps.com/dgnmhgnreg/public_html/myadmin

[Mon Jun 15 13:47:40 2015] [error] [client 65.186.77.14] instantiating restore controller e57fe0cbfe252c7eb607eddd106b5d63, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:40 2015] [error] [client 65.186.77.14] setting controller status to 100, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:40 2015] [error] [client 65.186.77.14] loading backup info, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] loading controller plan, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] setting controller status to 300, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] setting controller status to 500, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:41 2015] [error] [client 65.186.77.14] calculating controller checksum 25632424f326a43b19cc62b02e28b8cd, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:48 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:48 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:48 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:48 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:48 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:47:48 2015] [error] [client 65.186.77.14] calculating controller checksum 25632424f326a43b19cc62b02e28b8cd, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:48:36 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:48:36 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:48:41 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:48:41 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:48:41 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:48:41 2015] [error] [client 65.186.77.14] calculating controller checksum 1bb73e4d7844b3af8d931f8f3e868daf, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:48:59 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:48:59 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:06 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:06 2015] [error] [client 65.186.77.14] setting controller status to 600, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:06 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:06 2015] [error] [client 65.186.77.14] calculating controller checksum 3fd3631d8fe448f81a09d0aaf7b3f2ed, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:07 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:39 2015] [error] [client 65.186.77.14] setting controller status to 700, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:39 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:39 2015] [error] [client 65.186.77.14] calculating controller checksum 6a514926c870c60f8c3967acf4e377fb, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:40 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:49:40 2015] [error] [client 65.186.77.14] setting controller status to 800, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Mon Jun 15 13:52:49 2015] [error] [client 65.186.77.14] Potential coding error - existing temptables found when disposing database. Must be dropped!, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

 

 

 

A different attempt:

 

Here are the apache error log messages for this failed attempt at installing..

 

[Tue Jun 16 14:28:51 2015] [error] [client 65.186.77.14] instantiating restore controller 97223f272b24319bfd108819819461ae, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:51 2015] [error] [client 65.186.77.14] setting controller status to 100, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:51 2015] [error] [client 65.186.77.14] loading backup info, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] loading controller plan, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] setting controller status to 300, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] setting controller status to 500, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:28:52 2015] [error] [client 65.186.77.14] calculating controller checksum 2bb6932a643d9f1f7b7a5184962c4fb8, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:13 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:13 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:13 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:13 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:13 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:14 2015] [error] [client 65.186.77.14] calculating controller checksum 2bb6932a643d9f1f7b7a5184962c4fb8, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:50 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:50 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:55 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:55 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:55 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:29:55 2015] [error] [client 65.186.77.14] calculating controller checksum 2c53b262845ce820f44bb555355c0b7c, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:30:58 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:30:58 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:05 2015] [error] [client 65.186.77.14] checking plan security, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:05 2015] [error] [client 65.186.77.14] setting controller status to 600, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:05 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:05 2015] [error] [client 65.186.77.14] calculating controller checksum 3e8deb8ebe582c4963cdfa6c7d63a89e, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:05 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:34 2015] [error] [client 65.186.77.14] setting controller status to 700, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:34 2015] [error] [client 65.186.77.14] saving controller to db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:35 2015] [error] [client 65.186.77.14] calculating controller checksum 3f48f481de96aa3142862abb92d438ae, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:35 2015] [error] [client 65.186.77.14] loading controller from db, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php

[Tue Jun 16 14:31:35 2015] [error] [client 65.186.77.14] setting controller status to 800, referer: http://moodle-1840-18176-42202.cloudwaysapps.com/backup/restore.php