Backup time not working?

Discussion in 'General' started by snowfly, Sep 24, 2020.

  1. snowfly

    snowfly Member

    I run a multi server setup on ISPConfig 3.1.15p3, and just noticed that the servers where I've configured a "Backup time" are not adhering to this time.
    I set the backup time for each server by going to: System > Server Config > Select Server > Server Tab > Backup time

    Example, this server was set to a 5am backup time, which worked for some days, but then is at random times between 7 and 8am:
    -rwxr-x--- 1 root root 173406297 Sep 15 05:00 web992_2020-09-15_05-00.tar.gz
    -rwxr-x--- 1 root root 173406294 Sep 16 05:00 web992_2020-09-16_05-00.tar.gz
    -rwxr-x--- 1 root root 173406294 Sep 17 05:00 web992_2020-09-17_05-00.tar.gz
    -rwxr-x--- 1 root root 173406291 Sep 18 05:00 web992_2020-09-18_05-00.tar.gz
    -rwxr-x--- 1 root root 173406291 Sep 19 08:16 web992_2020-09-19_08-15.tar.gz
    -rwxr-x--- 1 root root 173406290 Sep 20 08:01 web992_2020-09-20_07-59.tar.gz
    -rwxr-x--- 1 root root 173406281 Sep 21 07:56 web992_2020-09-21_07-55.tar.gz
    -rwxr-x--- 1 root root 173406293 Sep 22 08:20 web992_2020-09-22_08-20.tar.gz
    -rwxr-x--- 1 root root 173406288 Sep 23 09:12 web992_2020-09-23_09-12.tar.gz
    -rwxr-x--- 1 root root 173406287 Sep 24 08:38 web992_2020-09-24_08-37.tar.gz

    Ideally I want to stagger our web servers, so the backups are taken at 3am, 4am, 5am, etc.
    Rather than backups happening randomly at 7am or 8am or 9am, which can cause extra load on these web servers when they are trying to serve websites to users, and then those users complain about slow websites!

    Any tips on how to fix this?
    Thanks
     
  2. till

    till Super Moderator Staff Member ISPConfig Developer

    The timestamp of the file shows when a specific backup ended for that website, so its no indication that the backup did not started at 5am for the first website. let's say you have 50 websites on that server and the backup of each site takes 5 minutes, then you have to calc 50x5 = 250 minutes until the last backup on this server ended.
     
  3. snowfly

    snowfly Member

    Sorry I should have added more details, as the backups are not starting at the configured tim.
    On one server called 'web01', I configured to start at 1:30am, BUT the backups are not starting until 8am.
    I check this by running this command in a folder where all the backups are mounted to:
    ls -l -rt web*/web*_2020-09-28*.tar.gz
    Which results in backups starting from 8am:
    -rwxr-x--- 1 admin administrators 61834807 2020-09-28 08:00 web676/web676_2020-09-28_08-00.tar.gz*
    -rwxr-x--- 1 admin administrators 679650 2020-09-28 08:00 web956/web956_2020-09-28_08-00.tar.gz*
    -rwxr-x--- 1 admin administrators 314634 2020-09-28 08:00 web957/web957_2020-09-28_08-00.tar.gz*
    -rwxr-x--- 1 admin administrators 48335698 2020-09-28 08:00 web3106/web3106_2020-09-28_08-00.tar.gz*
    -rwxr-x--- 1 admin administrators 356930198 2020-09-28 08:01 web3242/web3242_2020-09-28_08-00.tar.gz*
    -rwxr-x--- 1 admin administrators 13279191 2020-09-28 08:02 web1885/web1885_2020-09-28_08-01.tar.gz*
    ....
    and these continue all the way to 8:46am when the backups finished on this server:
    -rwxr-x--- 1 admin administrators 11922487 2020-09-28 08:46 web1012/web1012_2020-09-28_08-46.tar.gz*
    -rwxr-x--- 1 admin administrators 130409 2020-09-28 08:46 web833/web833_2020-09-28_08-46.tar.gz*
    -rwxr-x--- 1 admin administrators 10130625 2020-09-28 08:46 web1013/web1013_2020-09-28_08-46.tar.gz*

    The same goes for other servers we have, web02, web03, etc, which have different configured start times (e.g. 5am), but their backups don't start until later in the day.
     
  4. snowfly

    snowfly Member

    I've done some more investigation on this, and found that the ISPConfig cron has large gaps during the early morning, when the backup job should be running, but isn't.
    First I set $conf['log_priority'] = 0, for debug, in the file: /usr/local/ispconfig/server/lib/config.inc.php
    (I did this on 3 different web servers).

    Then after a day I reviewed the log file on each server at: /var/log/ispconfig/cron.log (and /var/log/ispconfig/cron.log.1.gz)
    Interestingly, up to around 6 minutes past midnight (00:06), the cron log had debug like:
    Wed Oct 21 00:06:14 NZDT 2020 Included cronjob_awstats from /usr/local/ispconfig/server/lib/classes/cron.d/150-awstats.inc.php -> will now run job.
    Wed Oct 21 00:06:14 NZDT 2020 Called run() for class cronjob_awstats
    Wed Oct 21 00:06:14 NZDT 2020 Job has schedule: 0 0 * * *
    Wed Oct 21 00:06:14 NZDT 2020 Called onPrepare() for class cronjob_awstats
    Wed Oct 21 00:06:14 NZDT 2020 Called onBeforeRun() for class cronjob_awstats
    Wed Oct 21 00:06:14 NZDT 2020 Jobs next run is 2020-10-21 00:00:00
    Wed Oct 21 00:06:14 NZDT 2020 Jobs next run is now 2020-10-22 0:0:0
    ....

    And then there is a big time gap in the log, with no "Called..." debug lines until 8:01am - meaning the backup job isn't run at the right time (5am):
    Wed Oct 21 08:01:37 NZDT 2020 Called onRun() for class cronjob_awstats
    Wed Oct 21 08:01:37 NZDT 2020 Called onAfterRun() for class cronjob_awstats
    Wed Oct 21 08:01:37 NZDT 2020 Called onCompleted() for class cronjob_awstats
    Wed Oct 21 08:01:37 NZDT 2020 run job (cronjob_awstats) done.

    Does that mean the awstats job is taking 8 hours to run, so nothing else is run during that time?

    Also during that 8 hour period (midnight - 8am) there are lot of these log file entries, saying cron.php is already running:
    Wed Oct 21 04:25:01 NZDT 2020 21.10.2020-04:25 - WARNING - There is already an instance of cron.php running with pid 31913.
    Wed Oct 21 04:25:01 NZDT 2020 Set Lock: /usr/local/ispconfig/server/temp/.ispconfig_lock
    Wed Oct 21 04:25:01 NZDT 2020
    Wed Oct 21 04:25:01 NZDT 2020
    Wed Oct 21 04:25:01 NZDT 2020 21.10.2020-04:25 - DEBUG - Calling function 'check_phpini_changes' from plugin 'webserver_plugin' raised by action 'server_plugins_loaded'.
    Wed Oct 21 04:25:01 NZDT 2020 21.10.2020-04:25 - DEBUG - Remove Lock: /usr/local/ispconfig/server/temp/.ispconfig_lock
    Wed Oct 21 04:25:01 NZDT 2020 finished.


    Is that any cause for concern?

    Thanks.
     
  5. Jesse Norell

    Jesse Norell ISPConfig Developer Staff Member ISPConfig Developer

    I suspect that could explain why your backups don't run, if the lock file exists so that new cronjobs cannot start.

    I don't know, but checking running processes during that time should show you if it is (look for the pid mentioned in the log message, 'There is already an instance of cron.php running with pid 31913.').
     
    Gwyneth Llewelyn likes this.

Share This Page