Backups failing - some general questions

Backups failing - some general questions

por Nikolaas Dries -
Número de respuestas: 13
Hello all

I'm trying to make sense of the backup procedures and scripts so I can dial in my server (or change policies) to get my backups working again.

I put the details to the bottom of this post, so you don't have to scroll too far down to get to my questions.

The problem:
Our site has 300+ courses. Schools are closed in Belgium now, so I've seen a huge increase in Moodle usage. Some colleagues have asked their students to take pictures of their workbooks and upload them. Movie clips for speaking exercises were handed in as well.

Whenever a course seems to go over approximately 2.2gb, I get a report one or two of them have failed. Evert few days, it's another course that had the problem. Which would imply that the course previously giving problems now were backed up.

If I manually back these courses up, through site or CLI (backup.php), they get done without a problem.
When I remove some materials from these courses, they backup just fine again.

I can use some help reviewing my server settings. And, as I am not really trained in php and server management (budgets, rules, ...), I've writting down some more general php questions, because I want to learn.

The main goal is, of course, to get the system going with minimal manual intervention. Preferably without restricting my users too much.

What have I tried and considered?
  1. Moved backup time to 2AM, to make sure the server isn't too busy.
  2. Cleaned out all temp backup files (I now remove the folders in there once a day).
  3. Increased php upload size and process timeout to values you can find below.
  4. Tried to get a script running to clean out all the failed backup folders in temp automatically.
  5. I've informed my users they need to have their users hand in smaller files (scan to pdf instead of picture).
  6. Flushing the backup tables (but I don't have the rights on my server).

The Questions

  • Is this really about size alone?
    Since it is always the largest two courses that seem to cause the problem, but the largest courses aren't always the same ones. Or is the concept 'large' more complicated and could it also depend on shared files and assignments?
  • Could it be another error that just times out the entire process?
  • Why can I do a single manual backup of this course, but won't it work through automated backups/cron?
    • How does time-out work vs cron? I presume the cron script calls subscripts. And I think the automated backup script calls the backup scrip for every course. Does a new time out timer start for every script? Or does the timer start at the beginning of the cron script for everything withing the scope of that script?
    • Same question as above, but for memory usage.
  • Can I flush the backup tables (log, control) while the site is live?
  • Not all of my tables are converted to utf8mb4_unicode. (Scheduled for the end of this week). Could this be related?

Site and server
  • 8 x 2,50 GHz CPU
  • 32 GB RAM
  • 640 GB SSD  (55% full)
  • 16 TB Bandwidth
Cron runs every 5 min.

php settings:

  • version: PHP 7.1 (ea-php71)
  • 64 bit
  • memory limit: 4096 MB
  • allow_url_fopen = On
    allow_url_include = On
    display_errors = Off
    enable_dl = On
    file_uploads = On
    max_execution_time = 600
    max_input_time = 500
    max_input_vars = 15000
    memory_limit = 4096M
    post_max_size = 4000M
    session.gc_maxlifetime = 1440
    upload_max_filesize = 4096M
    zlib.output_compression = Off

Error logs

Moodle backup log:

Last two lines are always the same.
10:50:02 - calculating controller checksum 65c49d43238f8c300cc74d290e909d07
10:50:02 - loading controller from db

Error_log

I've left out all the 'requireloginerror' entries. I've found two other types of error.

[01-Apr-2020 06:31:51 Europe/Brussels] Default exception handler: Fout bij het lezen van de databank Debug: MySQL server has gone away
SELECT id, sid, state, userid, lastip, timecreated, timemodified FROM mdl_sessions WHERE sid = ?
[array (
  0 => '88a9b8033340ba30ab2f0486019175eb',
)]
Error code: dmlreadexception
* line 486 of /lib/dml/moodle_database.php: dml_read_exception thrown
* line 1245 of /lib/dml/mysqli_native_moodle_database.php: call to moodle_database->query_end()
* line 1571 of /lib/dml/moodle_database.php: call to mysqli_native_moodle_database->get_records_sql()
* line 1543 of /lib/dml/moodle_database.php: call to moodle_database->get_record_sql()
* line 1522 of /lib/dml/moodle_database.php: call to moodle_database->get_record_select()
* line 327 of /lib/classes/session/manager.php: call to moodle_database->get_record()
* line 98 of /lib/classes/session/manager.php: call to core\session\manager::initialise_user_session()
* line 794 of /lib/setup.php: call to core\session\manager::start()
* line 29 of /config.php: call to require_once()
* line 30 of /index.php: call to require_once()



[04-Apr-2020 21:28:56 Europe/Brussels] Default exception handler: Kon bestand"1/core/preview/0/thumb/27e5128f15aa6156f1c2c09a7698e716c64417e3" niet maken Debug: Duplicate entry 'da810284efd3b7a236b3264b04d40329d683dfff' for key 'mdl_file_pat_uix'
INSERT INTO mdl_files (contextid,component,filearea,itemid,filepath,filename,timecreated,timemodified,userid,source,author,license,status,sortorder,contenthash,filesize,mimetype,pathnamehash) VALUES(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)
[array (
  0 => 1,
  1 => 'core',
  2 => 'preview',
  3 => 0,
  4 => '/thumb/',
  5 => '27e5128f15aa6156f1c2c09a7698e716c64417e3',
  6 => 1586028536,
  7 => 1586028536,
  8 => NULL,
  9 => NULL,
  10 => NULL,
  11 => NULL,
  12 => 0,
  13 => 0,
  14 => 'c3d710d587e5f43dcd0cfb4e5ce836697a9f1c10',
  15 => 5860,
  16 => 'image/png',
  17 => 'da810284efd3b7a236b3264b04d40329d683dfff',
)]
Error code: storedfilenotcreated
* line 1452 of /lib/filestorage/file_storage.php: stored_file_creation_exception thrown
* line 438 of /lib/filestorage/file_storage.php: call to file_storage->create_file_from_string()
* line 242 of /lib/filestorage/file_storage.php: call to file_storage->create_file_preview()
* line 2609 of /lib/filelib.php: call to file_storage->get_file_preview()
* line 88 of /draftfile.php: call to send_stored_file()





Promedio de valuaciones (ratings): -
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Visvanath Ratnaweera -
Imagen de Particularly helpful Moodlers Imagen de Translators
What you could try is to set the Automated backup setup (backup | backup_auto_active) to "manual" and run the CLI PHP script through crontab.

# crontab -u www-data -l
M H * * * /usr/bin/php /path/to/moodle/admin/cli/automated_backups.php
Promedio de valuaciones (ratings): -
En respuesta a Visvanath Ratnaweera

Re: Backups failing - some general questions

por Nikolaas Dries -
I presume this would have the same result as starting automated_backups by hand. I have tried that this morning. The problem persists.
I am now considering splitting the backups through my own scripts.

Thanks.
Promedio de valuaciones (ratings): -
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Visvanath Ratnaweera -
Imagen de Particularly helpful Moodlers Imagen de Translators
A single run of the script whether manually or through crontab are the same. The difference is, if the automated backup settings were done carefully, through the many repetitions the crontab does the job more and more efficiently, because the work becomes "incremental".

But the performance is not your problem. You have an offending course which breaks the course backup procedure. If you can find out which course that is, you can run the backup in two halves, avoiding that course.

For some reason your repository (mdl_files and moodledata/filedir/) is broken. Could be something minor, still Moodle's repository system is delicate. Once broken, reparing will be a nightmare. The rough solution would be to find out the offending course and delete it. May be others know more elegant solutions.

The key is:
Kon bestand"1/core/preview/0/thumb/27e5128f15aa6156f1c2c09a7698e716c64417e3" niet maken Debug: Duplicate entry 'da810284efd3b7a236b3264b04d40329d683dfff' for key 'mdl_file_pat_uix'
INSERT INTO mdl_files (contextid,component,filearea,itemid,filepath,filename,timecreated,timemodified,userid,source,author,license,status,sortorder,contenthash,filesize,mimetype,pathnamehash) VALUES(?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)
[array (
0 => 1,
1 => 'core',
2 => 'preview',
3 => 0,
4 => '/thumb/',
5 => '27e5128f15aa6156f1c2c09a7698e716c64417e3',
6 => 1586028536,
7 => 1586028536,
8 => NULL,
9 => NULL,
10 => NULL,
11 => NULL,
12 => 0,
13 => 0,
14 => 'c3d710d587e5f43dcd0cfb4e5ce836697a9f1c10',
15 => 5860,
16 => 'image/png',
17 => 'da810284efd3b7a236b3264b04d40329d683dfff',
)]
Promedio de valuaciones (ratings): -
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Ken Task -
Imagen de Particularly helpful Moodlers

While there is lots and lots to chat about concerning auto backups, there is one item of config for DB that could help you at this point.   Thanks for sharing clips of logs as without those would not be able to make any significant suggestion to impact your situation.

This 'MySQL server has gone away'  is due to a missing setting in DB config file (assuming my.cnf).   max_allowed_packet

mysql> show variables like 'max_allowed%';

add a line to my.cnf for the setting and increase the value seen from above ...  can't give exact value ... how about double?

Restart DB service.

Would also recommend installation and running of MySQLTuner.  Am almost certain you'll see other recommended tweaks that will help.

No ... am not a certified DB admin.  Just someone who has dug a lot!

Another suggestion to follow ... takes time to type it up! :|

'SoS', Ken

Promedio de valuaciones (ratings):Useful (1)
En respuesta a Ken Task

Re: Backups failing - some general questions

por Ken Task -
Imagen de Particularly helpful Moodlers

Quick follow up on MySQL Tuner ... live K12 production server that I have to check due to same situation ...

Key setttings ... that should show ok ..

MySQL Tuner
[OK] Maximum reached memory usage: 3.6G (11.38% of installed RAM)
[OK] Maximum possible memory usage: 4.4G (14.13% of installed RAM)
[OK] Overall possible memory usage with other process is compatible with memory available
[OK] Slow queries: 0% (0/51M)
[OK] Highest usage of available connections: 28% (130/451)
[OK] Aborted connections: 0.00%  (1/1146046)
[OK] InnoDB buffer pool / data size: 3.0G/2.5G
[OK] InnoDB buffer pool instances: 3

at bottom:
Variables to adjust:

On a server that has code + DB server, it becomes a balancing act between web service *and* DB server on the backend.

Via command line (same server as mentioned above ... this AM:

top

Mem:  32880592k total, 32531804k used,   348788k free,  1026552k buffers
Swap:  8208380k total,    96124k used,  8112256k free, 26816688k cached

SWAP is generally bad .. means more disk I/O ... slows server down.  On the server am checking right now the Swap line above shows swap 96124k used

I can live with that as it's almost impossible to reach 0 there!

Another follow up to follow after I finish checking that server!

'SoS', Ken


Promedio de valuaciones (ratings):Useful (2)
En respuesta a Ken Task

Re: Backups failing - some general questions

por Nikolaas Dries -
Thanks. I'm taking the site offline for maintenance on Thursday. I'll read up that mySQL tuner and the max_allowed_packet by then.
Promedio de valuaciones (ratings): -
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Ken Task -
Imagen de Particularly helpful Moodlers

A follow up ...

Again ... think key is DB config:

MySQL server has gone away
which will break any backup ... manual, automated or otherwise - an not always at the same place ... thus producing a different error and off into a very dark/deep rabbit hole!

Info shared on php settings showed no max_allowed_packet value which means variable set to defaults - which isn't enough.

Please see:

https://docs.moodle.org/38/en/MySQL
"Increase the 'max_allowed_packet' setting to at least 4 megabytes."

mysql> show variables like 'max_allowed_packet';

[root@moodle ktask]# fgrep 'max_allowed_packet' /etc/my.cnf
max_allowed_packet=950M

The very server where I've had the issue ... above setting is in place.

However, automated backups still can't be run successfully all the way through til completed.  1-2 courses break it.

'SoS', Ken

Promedio de valuaciones (ratings): -
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Ken Task -
Imagen de Particularly helpful Moodlers

Review backup defaults ... decide if you can live without the 'fluff' ... event logs? and other really not necessary for minimal backup.

Turn off automated backups and build a backup process that works ... no science to it ... some trial an error ... no one size fits all!

Am doing this on a K12 site ...

Use looping bash shell scripts that loop through course id files and
the CLI backup.php with switch to save to a designated directory where
you can see them by humanly recognizable names.

On a site that has 311 courses.txt
I have 4 such scripts.
One for Monday ... cids 2-99
Tuesday ... cids 100-199
Web ... cids 200-299
Thurs ... cids 300-311
(above cids exclude the large course cids)

nicllargebackups script ...

'non interactive cli large backups'

have determined which courses are large ... all the time due to nature of what is taught and how - multimedia .. videos/audios/digital photography ....

Because they might take a long time.
Friday ... late in day ...

Script looks like - has to be executed in moodle code cause backup.php uses config.php variables.

#!/bin/bash
#
# echo $1;
cd /var/www/html/moodle/admin/cli/;
for i in `cat /var/www/html/moodle/admin/cli/lc2.txt`
do
    echo "Course ID in que:" $i;
    php backup.php --courseid=$i --destination=/home/clibackups/
done
ls -l /home/clibackups/;
echo 'Done!';

lc2.txt file looks like

524
242
40
109

Teachers have been informed of above but it doesn't stop them from making backups of their own which I don't mind ... cept the teacher that uses up more than their fair share of resources on what is really a server for ALL!  And yes, I have found 6 copies of backups in that teachers area ... via sql query ... and manually remove 5 via CLI ... no issues to Moodle ... the backups simply do not appear to that teacher.  Given up on 'virtual hand slap'! triste   Do have the backing of 'ivory tower' admins in ISD to do what am doing, BTW!

Fingers crossed ... we've not had to use a backup restore for a messed up course.   But I attribute that to having sufficient memory and space + some tweaks from time to time ... yes, it's called server admin and monitoring ... and ... and ... being proactive when one can.

'SoS', Ken

Promedio de valuaciones (ratings):Useful (2)
En respuesta a Ken Task

Re: Backups failing - some general questions

por Nikolaas Dries -
Well, looks like I Amy need to go down thuis route. I have looked at your script, but I don't see any way you clean up old backups. Does the cli/backup script check the settings of the automated backups? Or do you a separate script or remove them by hand?
Promedio de valuaciones (ratings):Useful (1)
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Ken Task -
Imagen de Particularly helpful Moodlers

Moodle has 2 areas for backup preferences .... those for course backups that are in affect for Course Admin Menu backups *and* for admin/cli/backups.php.  The other is strictly for automated backups.

And no, don't have a remove/clean up old backups script.  That gets to be somewhat 'risky' in that doing from cli involves query of DB for .mbz files to get contenthash name, find for contenthash name in moodledata/filedir/, checking to make sure contenthash named file is a .mbz, removal of that file, and lastly removing the row in mdl_files table of DB.

However, check out moosh.

https://moosh-online.com/

https://moosh-online.com/commands/

'SoS', Ken


Promedio de valuaciones (ratings):Useful (1)
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Nikolaas Dries -
Update 1:
It is about time to open my site to the users again. The teacher want to start preparing for 'distance teache' after the holidays.
Unfortunately, the problem was not resolved yet.

For this one course that's giving me trouble , I will have to invoke my admin status and break it up into smaller peaces.

I'll put a write-up about my progress so far, because I have found searching through the forums a tremendous help.
  • This time I did not change anything in my php-settings.
  • I tried having the backup-controller and the backup-log- tables flushed.
  • max allowed packet in SQL was increased, first to 512 MB, then to 1GB. This is the maximum.

Note: I can still do a backup through the web interface. It mentions something about doing the work in an asynchronous way. I wonder if this different from running it through the CLI-scripts.

On the positive side: I have now found where I can get an overview of the resources being used by the sql database.

What's next?

Well, this article, which describes the MSQL server has gone away error and gives multiple solutions. One of these solutions is the increase of the max_allowed_packet, but it also mentions a connection timeout. This looks promising, as in the past I have increased the php script timout quite a bit. I can imagine the scripts now running longer than a connection to an SQL server is kept open.

A quick glance through the list of SQL variables gave me the two interesting tidbits:

connect_timeout
 The number of seconds that the mysqld server waits for a connect packet before responding with Bad handshake. The default value is 10 seconds.
Increasing the connect_timeout value might help if clients frequently encounter errors of the form Lost connection to MySQL server at 'XXX', system error: errno.

innodb_lock_wait_timeout
You might decrease this value for highly interactive applications or OLTP systems, to display user feedback quickly or put the update into a queue for processing later. You might increase this value for long-running back-end operations, such as a transform step in a data warehouse that waits for other large insert or update operations to finish.

Ken's SQLtuner didn't work for me. Not enough privileges on the VPS-server. But, I did find something similar in cPanel's phpMyadmin. Home>status>raadgever(Dutch - would translate to something like advice or counsel)
It is points out quite a few buffers and limits that can be open. I think there is some physical memory left over for this. I should check the logs.
But, I have restarted the SQL server a few times over the past days, and it tells me that's not enough time for a reliable analysis.

The error message that keeps returning:

[11-Apr-2020 14:30:45 Europe/Brussels] Potential coding error - existing temptables found when disposing database. Must be dropped!
[11-Apr-2020 14:30:45 Europe/Brussels] PHP Fatal error:  Uncaught ddl_change_structure_exception: DDL sql uitvoeringsfout (MySQL server has gone away
DROP TEMPORARY TABLE mdl_backup_ids_temp) in /home/ecollege/public_html/lib/dml/moodle_database.php:492
Stack trace:
#0 /home/ecollege/public_html/lib/dml/mysqli_native_moodle_database.php(1072): moodle_database->query_end(false)
#1 /home/ecollege/public_html/lib/ddl/database_manager.php(77): mysqli_native_moodle_database->change_database_structure('DROP TEMPORARY ...', Array)
#2 /home/ecollege/public_html/lib/ddl/database_manager.php(332): database_manager->execute_sql_arr(Array, Array)
#3 /home/ecollege/public_html/lib/dml/moodle_temptables.php(140): database_manager->drop_table(Object(xmldb_table))
#4 /home/ecollege/public_html/lib/dml/moodle_database.php(405): moodle_temptables->dispose()
#5 /home/ecollege/public_html/lib/dml/mysqli_native_moodle_database.php(610): moodle_database->dispose()
#6 /home/ecollege/public_html/lib/dml/moodle_database.php(160): mysqli_native_moodle_database->dispose()
#7 [internal functi in /home/ecollege/public_html/lib/dml/moodle_database.php on line 492
Promedio de valuaciones (ratings): -
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Ken Task -
Imagen de Particularly helpful Moodlers

You will have to fix this:

"PHP Fatal error:  Uncaught ddl_change_structure_exception: DDL sql uitvoeringsfout (MySQL server has gone away"

or there is no further discussion/cussion about it.

"SQLtuner didn't work for me. Not enough privileges on the VPS-server"

Well, you are the only customer on your VPS, right?
Why couldn't you know/be able to use superuser credentials with your own
database server? In an ssh session to server you can su to root ... or even use sudo -s right?

Depending upon where you are hosted (provider name please), the operating system,  somewhere on your system those superuser credentials are known and do exist other wise your site would not be able to be up when/if server is rebooted ... like after kernel updates.  And I do hope your server is getting operating system updates.

I'll answer the above for you:

You are hosted with Linode.
Hints clues for superuser creds
https://www.linode.com/community/questions/1140/mysql-root-password

"You cound have a password set in /etc/my.cnf or ~/.my.cnf"

ssh into server.
where ever you land, see if there is a hidden .my.cnf file
ls -l .my.cnf
That 'dot' in front is important ... hides files from normal commands listing/viewing files.
IF it does exist, can you edit?
ls -l should have shown ownerships/permissions.

** don't do this one first **  repeat .... don't ...
https://www.linode.com/community/questions/17930/retrieve-mysql-and-root-password

Suggest that just maybe your best source for resolution to this lies with Linode helpdesk or even their community forums.

'SoS', Ken

Promedio de valuaciones (ratings):Useful (1)
En respuesta a Nikolaas Dries

Re: Backups failing - some general questions

por Nikolaas Dries -

Last update - problem solved

Well, I'm now successfuly backing up courses of 6 tot 7 GB. I'll do a quick write-up of what I did, for anyone stumbling upon this topic.

After reading this again (https://haydenjames.io/mysql-server-has-gone-away-error-solutions) I asked the hosting company to change the settings below (after verifying I wasn't doing anything obviously stupid):

SQL

  • Wait-timeout: 600
  • Net read read timeout: 120
  • Net write timeout: 120
  • innodb_log_file_size: 3 gb (20% of 16gb in innodb buffer pool size)

PHP

  • Mysql.connect_timout: 610
  • mysql.allow_persistent=1
  • max_allowed_packet_size=4GB
Most of these values can be even higher, but it works like this. I would suggest to anyone trying this to work in small increments.


Thank you all for your help.


Promedio de valuaciones (ratings):Useful (1)