Automated course backups only occur every second day, not nightly

Automated course backups only occur every second day, not nightly

by Paul Lindgreen -
Number of replies: 8
Picture of Particularly helpful Moodlers

Course backup cron job occurs every night but courses are only backed up every second day.

Moodle cron logs indicate backup task starts and runs (hangs) but no courses are backed up every second day, every second day it works though. No completion message seen on failure days unlike the successful days (see cron messages below).

My cron job is run separately from Moodle scheduled tasks (disabled that scheduled task in Moodle. using Windows Scheduled Task). I separated it as it runs a very long time for 1000 courses, 12hr or so, and noticed this interfered with another moodle cron job.

No logs in Moodle Backup Reports, not sure why, what setting should I enable for backup logging, will this help?

What other sources of troubleshooting data can I find for this course backup that hangs every second day?

 logs1


Moodle Cron Log output for days that fail:

Server Time: Wed, 23 May 2018 21:15:01 -0300

Checking automated backup status...OK

Getting admin info

Checking courses

Skipping deleted courses...0 courses

Running required automated backups...

... started 21:15:01. Current memory use 16MB.

Backing up Moodle...

Server Time: Wed, 23 May 2018 21:45:01 -0300

 

Checking automated backup status...RUNNING

Automated backups are already running. If this script is being run by cron this constitues an error. You will need to increase the time between executions within cron.

Automated cron backups completed correctly

Execution took 0.140625 seconds

Server Time: Wed, 23 May 2018 22:15:01 -0300

 

Checking automated backup status...RUNNING

Automated backups are already running. If this script is being run by cron this constitues an error. You will need to increase the time between executions within cron.

Automated cron backups completed correctly

Execution took 0.28125 seconds

Cron Logs Successful days output:

Server Time: Thu, 24 May 2018 21:00:24 -0300

Checking automated backup status...Automated backups activity not found in last 90 minutes. Cleaning running status

OK

Getting admin info

Checking courses

Skipping deleted courses...0 courses

Running required automated backups...

... started 21:00:24. Current memory use 16MB.

Backing up Moodle...

…………..

1000 course back up messages

……......

complete - next execution: Thu, 24 May 2018 21:05:00 -0300


Automated backup settings

logs3

logs4

 ====================

environment:

moodle 3.1.5/Windows2008/IIS7.5/php5.6/mysql




Average of ratings: -
In reply to Paul Lindgreen

Re: Automated course backups only occur every second day, not nightly

by Ken Task -
Picture of Particularly helpful Moodlers

Don't have an answer readily ... but a few questions and things to check ...

Questions: is there a reason to store the backup in two places?   One in filedir of moodledata and one to a designated directory?

That's two copies ... and that's what moodle code uses once it has sucessfully build a backup in /moodledata/temp/backup/ ... a copy routine.

What is remaining in moodledata/temp/backup/ ?   You should see 0 byte size hashnamedfiles.log if a backup was successfull ... any .log file that's larger than 0 bytes had some sort of issue ... and only by viewing the log would one know anything specific to a course.

There is a task for cleaning up ... is that possibly romping on autobackups that didn't finish?

1000 courses is quite a few and depending upon the 'size' or 'heavy usage' of a course some could take quite a bit of time to backup successfully.    If you find hashnamed directories in moodledata/temp/backup/ investigate what's in them .... you actually might find .mbz files there which are valid backups, but server couldn't copy them to 2 locations for some reason.

I take it that your PHP is 64 bit and not 32?

BTW, I don't run Windows ... but have had go rounds with sites running Linux that had issues with large course backups and thus automatted backups.

'spirit of sharing', Ken


Average of ratings: -
In reply to Ken Task

Re: Automated course backups only occur every second day, not nightly

by Paul Lindgreen -
Picture of Particularly helpful Moodlers

re: Questions: is there a reason to store the backup in two places?   One in filedir of moodledata and one to a designated directory?

Currently inquiring whether its necessary, Ive removed this in our development environment and it reduced backup time by about 30%.

re: What is remaining in moodledata/temp/backup/ ?   You should see 0 byte size hashnamedfiles.log if a backup was successfull ... any .log file that's larger than 0 bytes had some sort of issue ... and only by viewing the log would one know anything specific to a course.

There are 1180 log files, 0kb each.
7 folders, 3.2gb, (Ill look closer into these)

re: There is a task for cleaning up ... is that possibly romping on autobackups that didn't finish?
re: If you find hashnamed directories in moodledata/temp/backup/ investigate what's in them

'Clean backup tables and logs' , 10am every day, default setting, any suggestions for different setting? Ill investigate one of the larger folders from the temp/backup folder, perhaps there is a problematic course backup there. Any thoughts on why there are no course backup logs under Reports->Courses?

re: I take it that your PHP is 64 bit and not 32?

Currently using 64 bit windows 2008 but 32 bit php5.6 (64bit php 5.6 isn't fully supported on windows). Seem to recall Network Services staff saying something about a limitation for 32 bit though, ill double check about that. I though 32bit was only an issue for course backups greater than 4gb?



thanks for the advice.

 

Average of ratings: -
In reply to Paul Lindgreen

Re: Automated course backups only occur every second day, not nightly

by Ken Task -
Picture of Particularly helpful Moodlers

Be careful not to 'read in' nor conclude anything on a question.   All moodle's on any platform had, in the past, issues with backups and other routines when php was 32 version.   Linux had 64 bit before Windows but now with 7.0 and higher of PHP on that platform, it too has 64bit.

You need to id specific issues before going onto changing parameters for things like the task.  No don't have any recommendations for changes to task that might be related.   Advise not changing anything just yet.

Now to next ...


Average of ratings: -
In reply to Ken Task

Re: Automated course backups only occur every second day, not nightly

by Paul Lindgreen -
Picture of Particularly helpful Moodlers

re: If you find hashnamed directories in moodledata/temp/backup/ investigate what's in them

I reviewed the folders in temp/backup and the days moodle auto backups do not occur coincide with a folder containing a mysterious course id 1 that I never could understand. I am unable to view this course id or find it, https://zzzzzzzzzzzzz/course/view.php?id=1 just brings me to my dashboard.

The backup report for this course indicates it doesnt backup, always unfinished (see screenshots below). Several Pages of logs but they are all blank. This temp folder always has one large logstores.xml file (845mb).

The course.xml file (see details below) indicates there is no category, is course id 1 a special system course?

Should I try to manually delete or hide this course so it will not be backed up?

Thanks again.


====course.xml===

<?xml version="1.0" encoding="UTF-8"?>
<course id="1" contextid="2">
  <shortname>Moodle</shortname>
  <fullname>Moodle</fullname>
  <idnumber></idnumber>
  <summary></summary>
  <summaryformat>0</summaryformat>
  <format>site</format>
  <showgrades>1</showgrades>
  <newsitems>3</newsitems>
  <startdate>0</startdate>
  <marker>0</marker>
  <maxbytes>0</maxbytes>
  <legacyfiles>0</legacyfiles>
  <showreports>0</showreports>
  <visible>1</visible>
  <groupmode>0</groupmode>
  <groupmodeforce>0</groupmodeforce>
  <defaultgroupingid>0</defaultgroupingid>
  <lang></lang>
  <theme></theme>
  <timecreated>1344945335</timecreated>
  <timemodified>1435151052</timemodified>
  <requested>0</requested>
  <enablecompletion>0</enablecompletion>
  <completionnotify>0</completionnotify>
  <numsections>1</numsections>
  <category id="">
  </category>
  <tags>
  </tags>
</course>

courseid1

course2

Average of ratings: -
In reply to Paul Lindgreen

Re: Automated course backups only occur every second day, not nightly

by Ken Task -
Picture of Particularly helpful Moodlers

First, any hashnamed directory you find in moodledata/temp/backup/ could be removed manually without any ill affects.  If you find a .mbz file in one of them, it's probably a valid backup that you can 'move' out to another location.

If you were on linux, one could actually watch what was going on in there with a linux "watch" command and I do that from time to time on one troubled server to see what's going on.

Trouble with removing those contenthash directories is only when Moodle is trying to use one.  So to manually clean it out, turn off Automated backups for a little while and manually remove.

How many courses do you have?  

Of the backups you do have, which courses are the largest (have the largest .mbz file)?

Do you have any idea as to how long backing up all courses would take?

Those questions ... possibly extended below ... (*)

Course ID 1 is the front page of Moodle.   It is a 'course' and the reason you get thrown to your profile/landing page using the URL for the course id 1 is the way it should behave.

One can see in your screen shot of Last Execution, the front page backup scheduled for 31 Dec. ... while you don't see years there, would assume that means 2018 ... ie, this year.

Unfortunately, autobackups doesn't have a options to exclude course ID's in it's configuration.  As long as you have automated backups turned on and scheduled to run, course ID 1 will be included (cannot hide front page) .... and will always be the largest course in terms of the logs.xml you found.

Until this is reported as a bug ... and someone at Moodle HQ takes a look at it ... status quo will be the same.

Alternative work-around for now? ... suggestion and below is brief description of what I've had to do with one K12 site.

* there is a script in code/admin/cli/ that will backup a single course ... backup.php.   On one site I admin there is a team taught multimedia course whose basic content contains 60 Gig ... without students and student work.   As course is used every academic year, it grows depending upon the number of students enrolled and I have seen it as high as 130Gig. 

It's that one course that always kills autobackups.   So to 'work around' that, I have created two bash shell scripts that run through a list of course ID's ... largecids.txt is a list of course ID's whose base is 30Gig plus.  The 'largecoursesbu' bash shell runs backups on those courses via the admin/cli/backup.php script only on a weekend beginning early Sunday AM.

The other bash shell script I have runs though a course ID list of all other courses excluding the large ones and runs more frequently through out the week.

Autobackups config is set to manual - ie, run from command line.

Autobackups task is turned off but the clean up is checked/set not to kick in when running cron jobs out side of Moodle to backup courses.

NOT ideal ... not perfect ... but suffices for the site.

'spirit of sharing', Ken


Average of ratings: -
In reply to Ken Task

Re: Automated course backups only occur every second day, not nightly

by Ken Task -
Picture of Particularly helpful Moodlers

One more thing .... you've shared the autobackup settings for your site.   Have you reviewed/read what those options do and decided if an option 'fits' your goal or not?

LIke number of backups to keep ... and maximum number of backups to keep.   If saving to both filedir and to a designated directory, check the designated directory for backup files ... are all 1000 courses there?

There are 3 tables related to backups.
mdl_backup_controlers - this table is updated on each course backup.
mdl_backup_courses - this tracks courseid, laststarttime,lastendtime,laststatus,nextstartime.

If laststatus is 0 then backup failed.

query the mdl_backup_courses table to see how many have 'laststatus=0'

Those might be your problem courses ... for whatever reason.

If the scheduling is off ... messed up ... one might have to truncate mdl_backup_courses ... leave the table and it's columns, just remove all data ... to get a better idea of problem courses ... and regain 'crontrol' over automated backups.  Since that's the tracker truncating that table means moodle has no knowledge of automated backups ever having been run and thus, all courses might be backed up.

I had to do that with the mdl 3.1 site I mentioned in previous post.

'spirit of sharing', Ken

Average of ratings: -
In reply to Ken Task

Re: Automated course backups only occur every second day, not nightly

by Paul Lindgreen -
Picture of Particularly helpful Moodlers

Thanks for the suggestions. I've posted a feature request update for the ability to exclude specific courses, or at least omit course id 1 by default.

the bash shell solution looks good but I dont have the time to explore it since our automated course backups appear to have less importance these days thanks to the awesome Recycle Bin (what a life saver), we used to want these backups for accidental deletions of activities and courses. Its primarily for course archiving at the end of each term nowadays.

Average of ratings: -
In reply to Paul Lindgreen

Re: Automated course backups only occur every second day, not nightly

by Paul Lindgreen -
Picture of Particularly helpful Moodlers

there is a tracker item open which does provide the code hack to exclude course id 1 and any other course ids https://tracker.moodle.org/browse/MDL-60296

btw - What was the purpose of including course id 1 in automated course backups? Ours still fails and ruins the scheduled course backups, the following run works though, so every second run is our workaround.

Average of ratings: -