From 69ca5f4f31aaeae64fd5865fc3442bfb5706c8e2 Mon Sep 17 00:00:00 2001 From: ralf Date: Fri, 10 Mar 2023 08:33:07 +0100 Subject: [PATCH] * Admin/Setup: logging all DB backup operations to a text file db_backup.log in backup-directory --- api/src/Db/Backup.php | 110 ++++++++++++++++++++++---- api/src/Db/Schema.php | 6 +- setup/db_backup.php | 44 ++++++----- setup/templates/default/db_backup.tpl | 29 ++++--- 4 files changed, 142 insertions(+), 47 deletions(-) diff --git a/api/src/Db/Backup.php b/api/src/Db/Backup.php index 15771bdfd7..65fd2c5ba6 100644 --- a/api/src/Db/Backup.php +++ b/api/src/Db/Backup.php @@ -189,9 +189,9 @@ class Backup if (!$name) { //echo '-> !$name
'; // ! - if (!$this->backup_dir || !is_writable($this->backup_dir)) + if (empty($this->backup_dir) || !is_writable($this->backup_dir)) { - //echo ' -> !$this->backup_dir || !is_writable($this->backup_dir)
'; // ! + $this->log($name, $reading, null, lang("backupdir '%1' is not writeable by the webserver", $this->backup_dir)); return lang("backupdir '%1' is not writeable by the webserver",$this->backup_dir); } $name = $this->backup_dir.'/db_backup-'.date('YmdHi'); @@ -209,37 +209,40 @@ class Backup if(!class_exists('ZipArchive', false)) { $this->backup_files = false; - //echo ' -> (new ZipArchive) == NULL
'; // ! + $this->log($name, $reading, null, lang("Cant open %1, needs ZipArchive", $name)); return lang("Cant open %1, needs ZipArchive", $name)."
\n"; } - if(!($f = fopen($name, $mode))) + if(!($f = fopen($path=$name, $mode))) { //echo ' -> !($f = fopen($name, $mode))
'; // ! $lang_mode = $reading ? lang("reading") : lang("writing"); + $this->log($name, $reading, null, lang("Cant open '%1' for %2", $name, $lang_mode)); return lang("Cant open '%1' for %2", $name, $lang_mode)."
"; } - return $f; } - if(class_exists('ZipArchive', false) && !$reading && $this->backup_files) + elseif (class_exists('ZipArchive', false) && !$reading && $this->backup_files) { //echo '-> (new ZipArchive) != NULL && !$reading; '.$name.'
'; // ! - if(!($f = fopen($name, $mode))) + if (!($f = fopen($path=$name, $mode))) { - //echo ' -> !($f = fopen($name, $mode))
'; // ! $lang_mode = $reading ? lang("reading") : lang("writing"); + $this->log($name, $reading, null, lang("Cant open '%1' for %2", $name, $lang_mode)); return lang("Cant open '%1' for %2", $name, $lang_mode)."
"; } - return $f; } - if(!($f = fopen("compress.bzip2://$name.bz2", $mode)) && - !($f = fopen("compress.zlib://$name.gz",$mode)) && - !($f = fopen($name,$mode)) + elseif (!($f = fopen('compress.bzip2://'.($path=$name.'.bz2'), $mode)) && + !($f = fopen('compress.zlib://'.($path=$name.'.gz'),$mode)) && + !($f = fopen($path=$name,$mode)) ) { - //echo '-> !($f = fopen("compress.bzip2://$name.bz2", $mode))
'; // ! $lang_mode = $reading ? lang("reading") : lang("writing"); + $this->log($name, $reading, null, lang("Cant open '%1' for %2", $name, $lang_mode)); return lang("Cant open '%1' for %2", $name, $lang_mode)."
"; } + + // Log start of backup/restore + $this->log($path, $reading, true); + return $f; } @@ -280,7 +283,9 @@ class Backup { if ($count >= $this->backup_mincount)// { + $this->log($file, lang('Housekeeping removed')); $ret = unlink($this->backup_dir.'/'.$file); + if (!$ret) $this->log($file, 'remove', null, "Failed to remove $file"); if (($ret) && (is_array($files_return))) { array_push($files_return, $file); @@ -414,6 +419,7 @@ class Backup $name = $dir.'/database_backup/'.basename($list[0]); if(!($f = fopen($name, 'rb'))) { + $this->log($name, true, null, lang("Cant open '%1' for %2", $filename, lang("reading"))); return lang("Cant open '%1' for %2", $filename, lang("reading"))."
\n"; } } @@ -476,6 +482,7 @@ class Backup { if (!$this->db->transaction_commit()) { + $this->log($filename, true, false, lang('Restore failed')); return lang('Restore failed'); } } @@ -497,6 +504,9 @@ class Backup // search-and-register-hooks Api\Hooks::read(true); + // log end of successful restore + $this->log($filename, true, false); + return ''; } @@ -907,7 +917,7 @@ class Backup $res = $zip->open($filename, ZipArchive::CREATE); if($res !== TRUE) { - //echo ' -> !$res
'; // ! + $this->log($filename, false, null, lang("Cant open '%1' for %2", $filename, lang("writing"))); return lang("Cant open '%1' for %2", $filename, lang("writing"))."
\n"; } $file_list = $this->get_file_list($dir); @@ -975,11 +985,19 @@ class Backup { if ($this->backup_files && !$skip_files_backup) { + $this->log($name, false, null, lang("Cant open %1, needs ZipArchive", $name)); echo '
'.lang("Cant open %1, needs ZipArchive", $name)."
\n".'
'; } - fclose($f); - if (file_exists($name)) unlink($name); + // get actual filename from stream + $filename_parts = explode('://', stream_get_meta_data($f)['uri'] ?? $name); + + fclose($f); + //if (file_exists($name)) unlink($name); + + // log successful end of backup + $this->log(array_pop($filename_parts), false, false); + return TRUE; } // save files .... @@ -1002,6 +1020,10 @@ class Backup $zip->close(); fclose($f); unlink($name); + + // log successful end of backup + $this->log($filename, false, false); + return true; } @@ -1150,6 +1172,62 @@ class Backup return $def; } + + const LOG_FILE = 'db_backup.log'; + + /** + * Log backup and restore start- and stop-time, plus file-name, -size and sha1 hash + * + * @param string $file filename + * @param bool|string $restore true: 'Restore', false: 'Backup', string with custom label + * @param bool $start true: start of operation, false: end, null: neither + * @return void + */ + public function log(string $file, $restore, bool $start=null, string $error_msg=null) + { + $msg = (is_string($restore) ? $restore : ($restore ? 'Restore' : 'Backup')).' '; + if (isset($start)) + { + $msg .= $start ? 'started ' : 'finished '; + } + $msg .= 'at '.date('Y-m-d H:i:s e').' '; + if (!empty($GLOBALS['egw_setup'])) + { + $msg .= 'from setup: '; + } + elseif (!empty($GLOBALS['egw_info']['user']['account_lid'])) + { + $msg .= 'by user '.$GLOBALS['egw_info']['user']['account_lid'].': '; + } + $msg .= ($path = $file[0] === '/' ? $file : $this->backup_dir.'/'.$file).' '; + if (empty($this->backup_dir) || !file_exists($path)) + { + if (empty($error_msg) && (!$start || $restore)) + { + $msg .= 'NOT existing!'; + } + } + else + { + $msg .= sprintf('%3.1f MB (%d)',filesize($path)/(1024*1024), filesize($path)).' sha1: '.sha1_file($path); + } + if (!empty($error_msg)) + { + $msg .= ' ERROR: '.$error_msg; + } + + // try opening log-file in backup-dir, or /var/lib/egroupware + if (!empty($this->backup_dir) && ($f = fopen($this->backup_dir.'/'.self::LOG_FILE, 'a')) || + ($f = fopen('/var/lib/egroupware/'.self::LOG_FILE, 'a'))) + { + fwrite($f, $msg."\n".(!$start ? "\n" : '')); + fclose($f); + } + else + { + error_log("Could NOT open ".self::LOG_FILE.': '.$msg); + } + } } /* diff --git a/api/src/Db/Schema.php b/api/src/Db/Schema.php index 2774319a66..7b4051f434 100644 --- a/api/src/Db/Schema.php +++ b/api/src/Db/Schema.php @@ -1101,6 +1101,8 @@ class Schema echo '

'.$msg."
\n".($backtrace ? 'Backtrace: '.function_backtrace(1)."

\n" : ''); } + const DEFAULT_TIMESTAMPS = ['current_date', 'current_timestamp', 'now()', 'curdate()']; + /** * Converts an eGW table-definition array into an ADOdb column-definition string * @@ -1155,7 +1157,7 @@ class Schema case 'date': $ado_col = 'D'; // allow to use now() beside current_date, as Postgres backups contain it and it's easier to remember anyway - if (in_array($col_data['default'],array('current_date','now()'))) + if (in_array(strtolower($col_data['default']), self::DEFAULT_TIMESTAMPS)) { $ado_col .= ' DEFDATE'; unset($col_data['default']); @@ -1190,7 +1192,7 @@ class Schema case 'timestamp': $ado_col = 'T'; // allow to use now() beside current_timestamp, as Postgres backups contain it and it's easier to remember anyway - if (in_array($col_data['default'],array('current_timestamp','now()'))) + if (in_array(strtolower($col_data['default']) , self::DEFAULT_TIMESTAMPS)) { $ado_col .= ' DEFTIMESTAMP'; unset($col_data['default']); diff --git a/setup/db_backup.php b/setup/db_backup.php index f6eca27aef..9ad71d3f72 100644 --- a/setup/db_backup.php +++ b/setup/db_backup.php @@ -41,7 +41,7 @@ $asyncservice = new Api\Asyncservice(); if (!empty($_POST['download'])) { $file = key($_POST['download']); - $file = $db_backup->backup_dir.'/'.basename($file); // basename to now allow to change the dir + $file = $db_backup->backup_dir.'/'.basename($file); // basename to not allow to change the dir // FIRST: switch off zlib.output_compression, as this would limit downloads in size to memory_limit ini_set('zlib.output_compression',0); @@ -50,6 +50,7 @@ if (!empty($_POST['download'])) Api\Header\Content::type(basename($file)); readfile($file); + $db_backup->log($file, 'Downloaded'); exit; } $setup_tpl = new Framework\Template($tpl_root); @@ -88,7 +89,7 @@ else $run_in_egw = true; } // save backup housekeeping settings -if ($_POST['save_backup_settings']) +if (!empty($_POST['save_backup_settings'])) { $matches = array(); preg_match('/^\d*$/', $_POST['backup_mincount'], $matches); @@ -112,7 +113,7 @@ if ($_POST['save_backup_settings']) } } } -if ($_POST['mount']) +if (!empty($_POST['mount'])) { Vfs::$is_root = true; echo '
'. @@ -123,11 +124,10 @@ if ($_POST['mount']) Vfs::$is_root = false; } // create a backup now -if($_POST['backup']) +if (!empty($_POST['backup'])) { if (is_resource($f = $db_backup->fopen_backup())) { - echo '

'.lang('backup started, this might take a few minutes ...')."

\n"; $starttime = microtime(true); $db_backup->backup($f); if(is_resource($f)) @@ -147,7 +147,9 @@ if($_POST['backup']) $setup_tpl->set_var('error_msg',$f); } } -$setup_tpl->set_var('backup_now_button',''); +$setup_tpl->set_var('backup_now_button',''); $setup_tpl->set_var('upload','  '. ''); $setup_tpl->set_var('backup_mincount',''); @@ -158,22 +160,22 @@ $setup_tpl->set_var('backup_files','set_var('backup_save_settings',''); $setup_tpl->set_var('backup_mount',''); -if ($_POST['upload'] && is_array($_FILES['uploaded']) && !$_FILES['uploaded']['error'] && +if (!empty($_POST['upload']) && is_array($_FILES['uploaded']) && !$_FILES['uploaded']['error'] && is_uploaded_file($_FILES['uploaded']['tmp_name'])) { - move_uploaded_file($_FILES['uploaded']['tmp_name'],$db_backup->backup_dir.'/'.$_FILES['uploaded']['name']); + move_uploaded_file($_FILES['uploaded']['tmp_name'], $filename=$db_backup->backup_dir.'/'.$_FILES['uploaded']['name']); - $md5 = ', md5='.md5_file($db_backup->backup_dir.'/'.$_FILES['uploaded']['name']); - $md5 .= ', sha1='.sha1_file($db_backup->backup_dir.'/'.$_FILES['uploaded']['name']); + $md5 = ', md5='.md5_file($filename).', sha1='.sha1_file($filename); - $setup_tpl->set_var('error_msg',lang("succesfully uploaded file %1",$_FILES['uploaded']['name'].', '. - sprintf('%3.1f MB (%d)',$_FILES['uploaded']['size']/(1024*1024),$_FILES['uploaded']['size']).$md5)); + $setup_tpl->set_var('error_msg', ($msg=lang("succesfully uploaded file %1", $filename.', '. + sprintf('%3.1f MB (%d)',$_FILES['uploaded']['size']/(1024*1024),$_FILES['uploaded']['size']))).$md5); + $db_backup->log($filename, $msg); } // delete a backup if (!empty($_POST['delete'])) { - $file = key($_POST['delete']); - $file = $db_backup->backup_dir.'/'.basename($file); // basename to not allow to change the dir + $file = $db_backup->backup_dir.'/'.basename(key($_POST['delete'])); // basename to not allow to change the dir + $db_backup->log($file, lang("backup '%1' deleted", $file)); if (unlink($file)) $setup_tpl->set_var('error_msg',lang("backup '%1' deleted",$file)); } @@ -190,7 +192,11 @@ if (!empty($_POST['rename'])) $file = $db_backup->backup_dir.'/'.basename($file); // basename to not allow to change the dir $ext = preg_match('/(\.gz|\.bz2)+$/i',$file,$matches) ? $matches[1] : ''; $new_file = $db_backup->backup_dir.'/'.preg_replace('/(\.gz|\.bz2)+$/i','',basename($new_name)).$ext; - if (rename($file,$new_file)) $setup_tpl->set_var('error_msg',lang("backup '%1' renamed to '%2'",basename($file),basename($new_file))); + if (rename($file,$new_file)) + { + $setup_tpl->set_var('error_msg',lang("backup '%1' renamed to '%2'",basename($file),basename($new_file))); + $db_backup->log($new_file, lang("backup '%1' renamed to '%2'",basename($file),basename($new_file))); + } } } // restore a backup @@ -201,7 +207,6 @@ if (!empty($_POST['restore'])) if (is_resource($f = $db_backup->fopen_backup($file,true))) { - echo '

'.lang('restore started, this might take a few minutes ...')."

\n".str_repeat(' ',4096); $start = time(); $db_backup->restore($f, true, $file); // allways convert to current system charset on restore $setup_tpl->set_var('error_msg',lang("backup '%1' restored",$file).' ('.(time()-$start).' s)'); @@ -274,11 +279,14 @@ foreach($files as $file => $ctime) 'mod' => date('Y-m-d H:i',$ctime), 'size' => sprintf('%3.1f MB (%d)',$size/(1024*1024),$size), 'actions' => ' '."\n". + ($file === Api\Db\Backup::LOG_FILE ? '' : ' '."\n". ' '."\n". - '', + ''), )); $setup_tpl->parse('set_rows','set_row',true); } diff --git a/setup/templates/default/db_backup.tpl b/setup/templates/default/db_backup.tpl index 5372e47593..15c8c1eb38 100644 --- a/setup/templates/default/db_backup.tpl +++ b/setup/templates/default/db_backup.tpl @@ -1,7 +1,14 @@

{error_msg}

-