Backup error within a course (courseid = 1)

Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -
Number of replies: 24

Hello

We have a problem with the automated backup since the moodle update to 3.2.x. Actually we're on Moodle 3.2.4+ (Build: 20170901).

More details:

The only affected course is the course with the id 1. All other courses ( > 2800) are running properly.

What are the correct steps to figure out the failure? I've already read some threads (like this https://moodle.org/mod/forum/discuss.php?d=323699) and I'm unsure what's the best approach.

I've already tested some things on a dev environment and came to this results:

  • Unfinished state should be change to error! So the next time the automated backup cronjob runs the job on this course.
  • On database I've checked/changed the status ids and changed it manually from unfished to error!

What's also strange is the additonal information on the reports (see screen). Should I change manually the unixtime on the database?


What should I do? The point is, that the error is on a productive environment and I can't do and force debugging on that server.

Attachment error.PNG
Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

Course ID 1 is the Moodle sites front page.

In admin/cli/ of the moodle code, there is a CLI script called backup.php.   It will backup individual courses.   Issuing from command line and in admin/cli/ just the script: php backup.php will bring up the help page for the script.

cd /pathtomoodlecode/admin/cli/

php backup.php --courseid=1 --destination=/somepath/outside/of/moodledata/and/moodlecode

Errors will be reported to the terminal screen.   If not, issue the same command but try inserting

'-d display_errors' after php and before backup.php.

The script will use whatever defaults you have set for backups.

Let's see if we can't get Moodle to report an error and go from there.

Note can see the date of the next scheduled backup has already passed ... it doesn't show a year but the month of Aug.

You might have to manipulate tables related to backups for course ID 1 to straighten it out.

Right after issuing the command, think I'd open another terminal session with server and go to:

/path/to/moodledata/temp/backup/

Then issue: watch 'ls -lR' [ENTER] to see what the backup script is doing - that's realtime.

'spirit of sharing', Ken


Average of ratings: Useful (2)
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -

I've now done the backup manually and the backup process completes without error but the associated logfile is empty having a size of 0KB.

The generated .mbz file contains the xml files and the activities data.


Output on prod console is:

[root@<hostname> cli]# php backup.php --courseid=1 --destination=/tmp

== Performing backup... ==

Writing /tmp/<backupfile>.mbz

Backup completed.

When I do the same on our development environment I get an output with:

[root@<hostname> cli]# php backup.php --courseid=1 --destination=/tmp

== Performing backup... ==

instantiating backup controller 90ed2f41604aa618a3c70145674be0fc

setting controller status to 100

loading controller plan

setting controller status to 300

applying plan defaults

setting controller status to 400

setting file inclusion to 1

checking plan security

setting controller status to 500

setting controller status to 700

saving controller to db

calculating controller checksum f53848be101b4b7829b5912c5f808182

loading controller from db

setting controller status to 800

setting controller status to 1000

saving controller to db

Writing /tmp/<backupfile>.mbz

Backup completed.

Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

Log files with 0 bytes is good.   Completed successfully.

So we know the front page (course ID 1) can be backed up without error.   Should also work in automated backups then I would think if the log/data on that course is accurate.

To fix the issue in automated backups, think you will have to manually edit the row in mdl_backup_courses for course ID 1.

select * from `mdl_backup_courses` where `courseid` like "1"

There are columns which are unix epoch time stamps and a status column.

You could change the data to match that of a course that has completed successfully to get the autobackups back in sync with the automated backups schedule.

'spirit of sharing', Ken

Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -

Hello Ken

Thanks for your help. So I've now simulated it on our development moodle. I change the laststarttime, lastendtime, nextstarttime and laststatus according to the productive values.


Then I run the automated backup script manually with:

  • sudo -u apache /usr/bin/php admin/cli/automated_backups.php

After the first run the status of the course changed from "Unfinished" to "Error".  So I relaunch the backup process (see cmd above) and then it successfull completed and the status is "OK".


Now, when the status from "Unfinished" don't changes to "Error", should I "force" it manually with laststatus? I think it doesn't makes a difference, what do you think?


I'll tell you in the next days, what are my results...

Kind Regards
Adrian

Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

It's an automated process and will always take courses sequentially ... 1 through whatever CID is last.  Having an issue with the front page backup (CID #1) could be problematic to the entire script. 

The only reason I suggested manipulating the DB tables was the nextrun date had already past and meant it would never be run again.    One should not resort to manipulating the DB to fix things ... last resort.

What I had to do with one system was truncate all the related tables .... by doing that, essentially, it was like Moodle had never run autobackups.    All tables then would have new data (dates/status) from the time it was run.   Then had to investigate individual courses that were problematic .... 96 Gig course, for example.    After having done this, had no more problems with automated backups on that system.

I would think that course ID 1 (the front page) should be small in comparison to other courses and should complete every time.

So before assuming the worse let's see how it goes with the next run. ;)

'spirit of sharing', Ken


Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -

Hello Ken

So I changed over night the database entry for courseid 1. But the backup fails! 

Here are some new information that I gathered (see attachements):

I don't know wheres the failure, I can't also find no files.xml file in the ../moodledata/temp/backup folder (1895529cfc19cbcf4ccf3b92a49acc70.zip).


What should I do next...?

Kind Regards
Adrian

Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

In the sql dump of backup logs, line 2 ....
activity skipped by _included settings
Syntax and Syntax error.

So what activities do you have on the front page?

Also, the last line ...
expects valid $filepath parameter.

relates to the place to store the backup - it appears.   Do you have the full path to where to save?

example:

/home/backup/m32/autobackups/

and does that directory belong to apache user/apache group?


So what settings do you have for autobackups as to destination of
the backups and what to backup?

At one time, in order to get autobackups working again, I had
to truncate the following tables:
mdl_backup_controllers
mdl_backup_courses
mdl_backup_logs

Tables stay, but data contained therein removed/erased.

This will result in moodle thinking it's never done an automated backup
of courses.   It will not erase the backups you have.

On the next run of autobackups, all new data (status/epoch time stamps, etc.) is entered.

Try this on your dev server first.

As a test on a 3.2.highest CentOS 7 server I have, I truncated the
above tables and ran autobackups via command line.
No errors.

'spirit of sharing', Ken

Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -

Hello Ken

Thanks for your thoughts. 

  1. I think the "error" logs are not related to the backup of the frontpage.
  2. Our frontpage have three blocks (2 own plugins and online users) included and the summary of site. When I do a manual backup I see that is included an announcement forum.
  3. The other courses are working well - so there's no problem with the savepath and it's permissions.
  4. Here are our automated backup settings:
  5. I tried your last hint to delete all containing automated backup data. And it worked well, but on our dev environment the automated backup is working when I run it manually.

It's hard to know what's the problem.

What about delete the backups of "course-1"?

[root@<hostname> moodlecoursebackup]# find . -name "*-course-1-*"

./sicherung-moodle2-course-1-ffhs_moodle-20170820-0555.mbz

./sicherung-moodle2-course-1-ffhs_moodle-20170823-0656.mbz

Like you can see, between the 12.July till now they worked in mid of august.

Attachment settings.png
Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

What does '2 own blocks' mean?   Are those 'standard core blocks' or customized blocks or blocks that might have dependencies?

Settings say keep 2.    So the files found show only 2 for ID 1 - although the dates are not consecutive.

Yes, remove those backup files (can't restore front page to front page anyway).   Let's see if, then, since you've scheduled to run every day, there are not 2 consecutive by date ID 1 backups.

Do same command line search for the next course ID.   Got 2 backups?

So of clearning all the tables related fixes this on dev, why not do same on production?

'spirit of sharing', Ken


Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -

Sry I must correct myself. We have only one customized block for our login (shibboleth - sso) the other ist the normal "login" block. I've setup the frontpage on dev identical to the productive site (summary site, three blocks) with the same settings.


I removed yesterday the two older backups and set the nextstarttime to the next scheduling. The same time I changed the laststatus to 5 (so it's like the first time the backup is processing). And it's still the same behaviour -> "Unfinished"!


How can I find out the last hash of the last backupjob for courseid1? Because we haven't debug enabled I can not find it in the logs. It's really hard to debug, when there are no exceptions and errors during the backup process.


And we don't want to truncate all tables related to the automated backups. What I've never done is to delete the "./../moodledata/temp/backup" folder.


Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

Too bad about removing the old CID 1 backups ... was going to suggest gunzipping them to see how large the .xml files were - in particular, the users.xml.    That's something I've not asked and you've not provided .... how many users on the system?   Also, what roles do you have assigned to the front page ... after successful login?   What activities/blocks do you have showing on the front page *after* login?

How many courses does site have?

Anything in moodledata/temp/backup/ is temporary and used for a build area for backups.   Safe to remove anything in moodledata/temp/backup/.    The temp directories in there should never conflict with other temp directories used to build a course - CID 1 would never get the same contenthashed named directory (if that's what were thinking).   If there is anything in moodledata/temp/backup/ delete it.   Next run of autobackups then, the only thing that should remain is all the course backups that failed - and according to what you've shared, the table shows only course ID 1 is unfinished so what remains in moodledata/temp/backup/ should be the front page.

You're on Linux ... so start the automated backup script in /admin/cli/ from command line in an ssh shell.   Open another terminal    Course ID 1 would be first to backup.   In the second terminal session, cd /path/to/moodledata/temp/backup/

ls -l

Should see the contenthashed directory created for the backup build ... long folder name ....

cd [thatlongfoldername]

Then:

watch "ls -lR"

and you can watch the build of the backup in *realtime*.

Your terminal session running the autobackup script will need to be left running and allowed to terminate it's own session (shouldn't kill the process, however).

As far as moodle retaining what contenthash named directory it was using to build a backup in some temp table ... uhhhhh, why?    If a backup fails, the directory will be there and thought it's name was the contenthash at the time.

What is so important about those tables related to autobackups that you do not want to truncate them?    Think at this point, I'd go with what worked on dev.

And just so you are clear ... you do know that CID 1 (the front page) cannot restored to the front page of a Moodle site, right?

At this point .... have suggested all I can think of ....  best of luck.

'spirit of sharing', Ken


Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -

Hello Ken

I didn't delete the old backup files of CID1. I just moved them to another folder. I've seen yesterday that this backups contains a >1GB logstores.xml file in ./course. So the frontpage backup contains the whole mdl_standard_log data? Can that be the problem, because we didn't clean them, we keep them atm forever.

The backup contains following data (attachement - say when you need more details):

  • users.xml (1KB, is empty)
  • roles.xml (1KB, only guest)

To answer the other questions:

  • We have about 5000 users and 3300 courses.
  • The defaultfrontpageroleid is "Authenticated user on frontpage (frontpage)".
  • We show only the "Online users" block.
Info: we redirect our users on login directly to the dashboard. And we force the users to first log in before the frontpage is visible.


Overnight I enabled Developer debugging on Moodle. So that was the output of the backup process (CID1):

Logs of the backup executed on Mittwoch, 27 September 2017, 12:50

Status - Unfinished

12:50:02 - instantiating backup controller a3781f901bff7b43f59725f0d9e7656c

12:50:02 - setting controller status to 100

12:50:02 - loading controller plan

12:50:02 - setting controller status to 300

12:50:02 - applying plan defaults

12:50:02 - setting controller status to 400

12:50:02 - setting file inclusion to 1

12:50:02 - checking plan security

12:50:02 - setting controller status to 700

12:50:02 - saving controller to db

12:50:02 - calculating controller checksum 5e4f322f298fe0ad54fb8ef2ba49c8d2

12:50:02 - loading controller from db

12:50:02 - setting controller status to 700

12:50:02 - saving controller to db

12:50:02 - calculating controller checksum ea085b5783fe8368a25cb362a853887f

12:50:02 - loading controller from db

12:50:02 - setting controller status to 800

I checked the data with the hash I see that logstores.xml is 0KB. The other files that where created are identical. I think creating this XML file the backup process makes troubles.


Thanks for sharing your knowledge.

Adrian

Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

Well, yeah ... not sure what 800 means as to what Moodle was doing, but a 0 byte logstores.xml meant it started the process of building that file but never finished.  If the logstores.xml was 1 Gig+ back then it surely has grown larger if you don't delete any logs.

In general backup defaults for courses, the default for keeping logs is none.

yoursite/admin/settings.php?section=backupgeneralsettings

Keep logs for X is set to what?  Default is 30 days.

Query your DB for the largest tables .... you will see that table is the largest.

The general backup defaults are used in autobackups.

If you look at Site Admin -> Report -> Logs ... note only site admins can access ... what information from 2 academic years past would be of use presently?

Do have many request from teachers for what student X did in a course during an Academic year or 2 Academic years ago?

Think I'd try to set things to a 'sane level' ... nothing is 'unlimited'!

'spirit of sharing', Ken


Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -

Hey Ken

Also the loglifetime for admin/settings.php?section=backupgeneralsettings is "365 days" and for admin/settings.php?section=logsettingstandard is "Never delete logs". But like you said the logsettingstandard doesn't get involved in the backup process.

So maybe I should try to set it from 365 days to an lower value like 1 day and retry it? So it shouldn't take a huge amount of logs during the backup process?

Sorry but I can't follow you with your latest described step:

If you look at Site Admin -> Report -> Logs ... note only site admins can access ... what information from 2 academic years past would be of use presently?
Do have many request from teachers for what student X did in a course during an Academic year or 2 Academic years ago?

Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

That last item was a question for you ... not a step  ... help decide how long to keep logs?   Appears no one has ever asked you to gen a report dealing with activity 2 years ago, etc., sooooooo ....

Well, resetting for how long to keep logs (now 365) to something lower should reduce the size that table on the next run of the cron/task.   But one day?    You might want to set that to something 'sane' ... but useful (should you need to look at those logs for some reason) ... length of a semester? ... or whatever your typical course length might be?   Can't make that call for ya.

'spirit of sharing', Ken


Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Séverin Terrier -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Testers Picture of Translators

Hi,

Another solution would be to backup every courses with logs, apart for the course 1 (front page). That would allow people wanting to keep logs for a very long time to do so, without beeing annoyed with backups.

Some modification of the code would be necessary for that.

Or, as i said previously, one could completly disable backup for the front page.

HTH,
Séverin

Average of ratings: -
In reply to Séverin Terrier

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

@Adrian ... what he said! (completely disable backup for the front page).

A thought ... if this will become a problem for most Moodle's, am wondering why the front page is backed up in the first place.   Can't restore the front page anyway.    The only reason I can think ... due to users ... could repopulate users to the same instance but that wouldn't carry their roles nor enrolled classes/work, would it?  So restore of CID 1 would work only for the same server ... not as a migration strategy?

Wouldn't it be nice to have an option(s) to define what courses to auto backup? ... either by selection of the courses or by usage (heaviest used).   I had to resort to creating two separate bash shell scripts using admin/cli/backup.php [meant for single course] ... looping through a list of course ID's .... one for very large courses (anywhere from 20 Gig to, believe or not, 139 Gig) and one for others as well as set those to cron jobs to provide automated backups for one site.   Those worked but the catch 22 was a new course wouldn't be automagically added to the 'smallcourses' CID list.

Anyhoo ....

'spirit of sharing', Ken


Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Séverin Terrier -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Testers Picture of Translators

Hi,

Some good ideas.

Other possibilities could be to add:

  • a text field, where admin could specify courses that should not be backuped
  • a text field, where admin could specify courses that should be backuped without logs

The first field would take preference on the second one.

These fields would default to void, or (course) 1.

Séverin

PS : just have to create tracker issue wink

Average of ratings: -
In reply to Séverin Terrier

Re: Backup error within a course (courseid = 1)

by Séverin Terrier -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Testers Picture of Translators
I've created MDL-60296 for my suggestions.

Don't hesitate to vote/comment !

Séverin
Average of ratings: -
In reply to Séverin Terrier

Re: Backup error within a course (courseid = 1)

by Séverin Terrier -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Testers Picture of Translators

Hi,

For those interested, but don't read the tracker, i've made a little hack to skip the site course backup (course=1) and a defined list of other courses (replace values "123, 1234, 12345" by id's of courses you want to skip) by adding these lines in backup/util/helper/backup_cron_helper.class.php (line 178 for Moodle 3.5.2, the last 2 existing lines indicate where to put it) :

                // Skip the site homepage course (1) - because it's useless and gigantic with logs
                if ($course->id == 1) {
                    $skipped = 1;
                    $skippedmessage = 'No backup of site home page!';
                }
 
                // Skip courses defined as to be skipped (because Admin knows they're too big)
                // Ideally admin could specify in UI a list of courses to skip - See MDL-60296
                $skipcourses = array(123, 1234, 12345);
                if (in_array($course->id, $skipcourses)) {
                    $skipped = 1;
                    $skippedmessage = 'No backup of this course (defined by Admin)!';
                }
 
                // Check if the course is not scheduled to run right now.
                if (!$shouldrunnow) {
Hope this helps,

I've also defined to backup masked courses, and my backups are ok for nearly 2500 courses (with 3 skipped) smile

Séverin
Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

If you were wondering why the output was different ... your dev server had debugging turned on thus you see the setting up of the backup controller and the executions of the setting controller status ... the stages/numbers 100 -> 1000 with the last (1000) indicating success backup.

With a site NOT in full debug mode, one gets the 3 liner.

Also ... your dev server may have started out as a clone of production server, but as time passes, they are no longer the same.   I wouldn't try to use data in backup tables from production and insert that data into dev.   When it comes to automated backups, let each server track the autobackups themselves.  Doctoring data from prod to dev might actually cause other issues or provide false/misleading info.

Again ... what do you have on your front page that's an activity?

Back front page up via the Moodle Admin UX.   Step through each page of the backup setup ... ie, don' t hyperjump to the end .... un-select activities ... if you have any on the front page.  OR make a backup of the front page selecting *only* those activities.   Let's see what happens.

'spirit of sharing', Ken




Average of ratings: -
In reply to Adrian Perez Rodriguez

Re: Backup error within a course (courseid = 1)

by Ken Task -
Picture of Particularly helpful Moodlers

Have one more question for investigation ... front page (course ID 1) roles.

First, don't admin any servers that have needed to change default roles on front page.

On servers where there is only authenticated users, the backup of the front page does have a users.xml and consist of only those users that are admin levels (vr. 3.1.highest).    And there are no forums on front page either.    Backups are very small.

Did help a gent one time that had some admin menu links displayed to students ... uhhhh, not good ... and it turned out to be roles assigned to front page.   After reverting roles (even deleting one that had been used when the site was remotely hosted with a Moodle Partner), that no longer happened.

Ok, am really out of ideas now!

'spirit of sharing', Ken

Average of ratings: -
In reply to Ken Task

Re: Backup error within a course (courseid = 1)

by Adrian Perez Rodriguez -

Hello all

I've now found our solution for our moodle environment. The problem is/was, that the mdl_logstore_standard_log table is too huge (in our case ~10GB) and then the backup.php scripts exthaustes the PHP memory limit.

So we have done this two steps:

  1. Set loglifetime to an other value (1000days in our case), https://<your-fqdn>/admin/settings.php?section=logsettingstandard. So the standard_log table doesn't increases undless. 
  2. Set extramemorylimit to an higher value (2048MB in our case), https://<your-fqdn>/admin/settings.php?section=performance. This was necessary in due of the huge mdl_logstore_standard_log table.

I think, when we don't restrict the loglifetime, the extramemorylimit must be increased time by time. At the moment our moodle plattform is only 2.5years old and logging. We will see, what happen in future.

Thanks all who helped us in our behaviour!

Kind Regards
Adrian

PS: The error was only displayed when the backup process was done in the UX of moodle. The error was only logged when the backup took place in the UX. I've never found these errors logged by the automatic or manual backup in the CLI.

Attachment backup_error_phplimit.PNG
Average of ratings: Useful (1)