N°2793 Log rotation (#117)

Now log file name is unchanged : current log is still /log/error.log \o/

Rotation check (using file last modification time) is done :
* on each file write : we don't want to miss calls if session last from 23:59:59 to 00:01 for example ! Though the filemtime() call is done once per session to lower performance impacts
* using a new background process (LogFileRotationProcess)

File renaming on setup is therefore removed.
Also the interface is renamed (from ILogFileNameBuilder to iLogFileNameBuilder) to conform to iTop convention.
This commit is contained in:
Pierre Goiffon
2020-03-02 15:01:12 +01:00
committed by GitHub
parent 6874aed4a2
commit 2be16f9078
3 changed files with 406 additions and 74 deletions

View File

@@ -2071,7 +2071,6 @@ class Config
$bReturn = fclose($hFile);
utils::SetConfig($this);
FileLog::RenameLegacyLogFiles();
return $bReturn;
}

View File

@@ -18,24 +18,36 @@
/**
* @since 2.7.0 N°2518
* @since 2.7.0 N°2518 N°2793
*/
interface ILogFileNameBuilder
interface iLogFileNameBuilder
{
public function __construct($sFileFullPath);
/**
* @param string $sLogFileFullPath full path name for the log file
*/
public function __construct($sLogFileFullPath = null);
/**
* @return string log file path we will write new log entry to
*/
public function GetLogFilePath();
}
class DefaultLogFileNameBuilder implements ILogFileNameBuilder
class DefaultLogFileNameBuilder implements iLogFileNameBuilder
{
private $sLogFileFullPath;
public function __construct($sFileFullPath)
/**
* @inheritDoc
*/
public function __construct($sLogFileFullPath = null)
{
$this->sLogFileFullPath = $sFileFullPath;
$this->sLogFileFullPath = $sLogFileFullPath;
}
/**
* @inheritDoc
*/
public function GetLogFilePath()
{
return $this->sLogFileFullPath;
@@ -45,60 +57,278 @@ class DefaultLogFileNameBuilder implements ILogFileNameBuilder
/**
* Adds a suffix to the filename
*
* @since 2.7.0 N°2518
* @since 2.7.0 N°2518 N°2793
*/
abstract class RotatingLogFileNameBuilder implements ILogFileNameBuilder
abstract class RotatingLogFileNameBuilder implements iLogFileNameBuilder
{
/**
* Test is done each time to cover edge case like session beginning at 23:59 and ending at 00:01
* We are caching the file mtime though
* @var array with full file path as key and DateTime (file last modification time) as value
*/
protected static $aLogFileLastModified = array();
/** @var string */
protected $sLogFileFullPath;
/** @var string */
protected $sFilePath;
/** @var string */
protected $sFileBaseName;
/** @var string */
protected $sFileExtension;
public function __construct($sFileFullPath)
/**
* @inheritDoc
*/
public function __construct($sLogFileFullPath = null)
{
$aPathParts = pathinfo($sFileFullPath);
$this->sLogFileFullPath = $sLogFileFullPath;
}
protected function GetLastModifiedDateForFile()
{
if (isset(static::$aLogFileLastModified[$this->sLogFileFullPath]))
{
return static::$aLogFileLastModified[$this->sLogFileFullPath];
}
return null;
}
protected function SetLastModifiedDateForFile($oDateTime)
{
static::$aLogFileLastModified[$this->sLogFileFullPath] = $oDateTime;
}
/**
* Need to be called when the file is rotated : actually the next call will need to check on the real date modified instead of using
* the previously cached value !
*/
public function ResetLastModifiedDateForFile()
{
static::$aLogFileLastModified[$this->sLogFileFullPath] = null;
}
/**
* @inheritDoc
*
* Doing the check before opening and writing the log file. There is also a iProcess but cron can be disabled...
*
* @see \LogFileRotationProcess the iProcess impl
*/
public function GetLogFilePath()
{
$this->CheckAndRotateLogFile();
return $this->sLogFileFullPath;
}
/**
* Check log last date modified. If too old then rotate the log file (move it to a new name with a suffix)
*
* @uses filemtime() to get log file date last modified
*/
public function CheckAndRotateLogFile()
{
if ($this->GetLastModifiedDateForFile() === null)
{
if ($this->IsLogFileExists())
{
return;
}
$iLogDateLastModifiedTimeStamp = filemtime($this->sLogFileFullPath);
if ($iLogDateLastModifiedTimeStamp === false)
{
return;
}
$this->SetLastModifiedDateForFile(DateTime::createFromFormat('U', $iLogDateLastModifiedTimeStamp));
}
$oNow = new DateTime();
$bShouldRotate = $this->ShouldRotate($this->GetLastModifiedDateForFile(), $oNow);
if (!$bShouldRotate)
{
return;
}
$this->RotateLogFile($this->GetLastModifiedDateForFile());
}
/**
* Rotate current log file
*
* @param DateTime $oLogFileLastModified date when the log file was last modified
*
* @uses \iTopMutex instead of flock as doing a rename on a file with a flock cause an error on PHP 5.6.40 Windows (ok on 7.3.15 though)
* @uses GetRotatedFileName to get rotated file name
*/
protected function RotateLogFile($oLogFileLastModified)
{
if (!$this->IsLogFileExists()) // extra check, but useful for cron also !
{
return;
}
$oLock = null;
try
{
$oLock = new iTopMutex('log_rotation_'.$this->sLogFileFullPath);
$oLock->Lock();
$this->ResetLastModifiedDateForFile();
$sNewLogFileName = $this->GetRotatedFileName($oLogFileLastModified);
rename($this->sLogFileFullPath, $sNewLogFileName);
}
catch (Exception $e)
{
// nothing to do, cannot log... file will be renamed on the next call O:)
return;
}
finally
{
if (!is_null($oLock)) { $oLock->Unlock();}
}
}
/**
* @param DateTime $oLogFileLastModified date when the log file was last modified
*
* @return string the full path of the rotated log file
* @uses static::$oLogFileLastModified
* @uses GetFileSuffix
*/
protected function GetRotatedFileName($oLogFileLastModified)
{
$aPathParts = pathinfo($this->sLogFileFullPath);
$this->sFilePath = $aPathParts['dirname'];
$this->sFileBaseName = $aPathParts['filename'];
$this->sFileExtension = $aPathParts['extension'];
}
public function GetLogFilePath()
{
$sFileSuffix = $this->GetFileSuffix();
$sFileSuffix = $this->GetFileSuffix($oLogFileLastModified);
return $this->sFilePath
.'/'
return $this->sFilePath.DIRECTORY_SEPARATOR
.$this->sFileBaseName
.'.'.$sFileSuffix
.'.'.$this->sFileExtension;
}
abstract protected function GetFileSuffix();
/**
* @return bool
*/
public function IsLogFileExists()
{
return !file_exists($this->sLogFileFullPath) || !is_readable($this->sLogFileFullPath);
}
/**
* @param DateTime $oLogFileLastModified date when the log file was last modified
* @param DateTime $oNow date/time of the log we want to write
*
* @return bool true if the file has older informations and we need to move it to an archive (rotate), false if we don't have to
*/
abstract public function ShouldRotate($oLogFileLastModified, $oNow);
/**
* @param DateTime $oDate log file last modification date
*
* @return string suffix for the rotated log file
*/
abstract protected function GetFileSuffix($oDate);
/**
* @see \LogFileRotationProcess
*
* @param \DateTime $oNow current date
*
* @return DateTime time when the cron process should run
*/
abstract public function GetCronProcessNextOccurrence(DateTime $oNow);
}
/**
* @since 2.7.0 N°2518
* @since 2.7.0 N°2518 N°2793
*/
class DailyRotatingLogFileNameBuilder extends RotatingLogFileNameBuilder
{
protected function GetFileSuffix()
/**
* @inheritDoc
*/
protected function GetFileSuffix($oDate)
{
return date('Y-m-d');
return $oDate->format('Y-m-d');
}
/**
* @inheritDoc
*/
public function ShouldRotate($oLogFileLastModified, $oNow)
{
$oInterval = $oNow->diff($oLogFileLastModified);
$iDaysDiff = $oInterval->d;
return $iDaysDiff > 0;
}
/**
* @inheritDoc
*/
public function GetCronProcessNextOccurrence(DateTime $oNow)
{
$oOccurrence = clone $oNow;
$oOccurrence->modify('tomorrow');
return $oOccurrence;
}
}
/**
* @since 2.7.0 N°2518
* @since 2.7.0 N°2518 N°2793
*/
class WeeklyRotatingLogFileNameBuilder extends RotatingLogFileNameBuilder
{
protected function GetFileSuffix()
/**
* @inheritDoc
*/
protected function GetFileSuffix($oDate)
{
$sWeekYear = date('o');
$sWeekNumber = date('W');
$sWeekYear = $oDate->format('o');
$sWeekNumber = $oDate->format('W');
return $sWeekYear.'-week'.$sWeekNumber;
}
/**
* @inheritDoc
*/
public function ShouldRotate($oLogFileLastModified, $oNow)
{
$iLogYear = $oLogFileLastModified->format('Y');
$iLogWeek = $oLogFileLastModified->format('W');
$iNowYear = $oNow->format('Y');
$iNowWeek = $oNow->format('W');
if ($iLogYear !== $iNowYear)
{
return true;
}
if ($iLogWeek !== $iNowWeek)
{
return true;
}
return false;
}
/**
* @inheritDoc
*/
public function GetCronProcessNextOccurrence(DateTime $oNow)
{
$oOccurrence = clone $oNow;
$oOccurrence->modify('Monday next week');
$oOccurrence->setTime(0, 0, 0);
return $oOccurrence;
}
}
/**
@@ -111,7 +341,7 @@ class LogFileNameBuilderFactory
*
* @param string $sFileFullPath
*
* @return \ILogFileNameBuilder
* @return \iLogFileNameBuilder
* @throws \ConfigException
* @throws \CoreException
*/
@@ -119,7 +349,7 @@ class LogFileNameBuilderFactory
{
$oConfig = utils::GetConfig();
$sFileNameBuilderImpl = $oConfig->Get('log_filename_builder_impl');
if (empty($sFileNameBuilderImpl) || !class_exists($sFileNameBuilderImpl))
if (!is_a($sFileNameBuilderImpl, iLogFileNameBuilder::class, true))
{
$sFileNameBuilderImpl = 'DefaultLogFileNameBuilder';
}
@@ -134,7 +364,7 @@ class LogFileNameBuilderFactory
*
* @copyright Copyright (C) 2010-2017 Combodo SARL
* @license http://opensource.org/licenses/AGPL-3.0
* @since 2.7.0 allow to rotate file (N°2518)
* @since 2.7.0 N°2518 N°2793 file log rotation
*/
class FileLog
{
@@ -153,52 +383,6 @@ class FileLog
$this->oFileNameBuilder = LogFileNameBuilderFactory::GetInstance($sFileName);
}
/**
* Since 2.7.0 with the 'log_filename_builder_impl' param the logs will output to different files name
* As now by default iTop will use {@link WeeklyRotatingLogFileNameBuilder} (rotation each week), to avoid confusion, we're renaming
* the legacy error.log / setup.log.
*
* @since 2.7.0 N°2518
* @uses utils::GetConfig() the config must be persisted !
*/
public static function RenameLegacyLogFiles()
{
$oConfig = utils::GetConfig();
IssueLog::Enable(APPROOT.'log/error.log'); // refresh log file used
$sLogFileNameParam = $oConfig->Get('log_filename_builder_impl');
$aConfigValuesNoRotation = array('', 'DefaultLogFileNameBuilder');
$bIsLogRotationActivated = (!in_array($sLogFileNameParam, $aConfigValuesNoRotation, true));
if (!$bIsLogRotationActivated)
{
return;
}
IssueLog::Warning("Log name builder set to '$sLogFileNameParam', renaming legacy log files");
$aLogFilesToRename = array(
'log/setup.log' => 'log/setup.LEGACY.log',
'log/error.log' => 'log/error.LEGACY.log',
);
foreach ($aLogFilesToRename as $sLogCurrentName => $sLogNewName)
{
$sSource = APPROOT.$sLogCurrentName;
if (!file_exists($sSource))
{
IssueLog::Debug("Log file '$sLogCurrentName' (legacy) does not exists, renaming skipped");
continue;
}
$sDestination = APPROOT.$sLogNewName;
$bResult = rename($sSource, $sDestination);
if (!$bResult)
{
IssueLog::Error("Log file '$sLogCurrentName' (legacy) cannot be renamed to '$sLogNewName'");
continue;
}
IssueLog::Info("Log file '$sLogCurrentName' (legacy) renamed to '$sLogNewName'");
}
}
public function Error($sText, $sChannel = '', $aContext = array())
{
$this->Write($sText, __FUNCTION__, $sChannel, $aContext);
@@ -427,3 +611,72 @@ class ToolsLog extends LogAPI
protected static $m_oFileLog = null;
}
class LogFileRotationProcess implements iScheduledProcess
{
/**
* Cannot get this list from anywhere as log file name is provided by the caller using LogAPI::Enable
* @var string[]
*/
const LOGFILES_TO_ROTATE = array(
'setup.log',
'error.log',
'tools.log',
'itop-fence.log',
);
/**
* @inheritDoc
*/
public function Process($iUnixTimeLimit)
{
$sLogFileNameBuilder = $this->GetLogFileNameBuilderClassName();
foreach (self::LOGFILES_TO_ROTATE as $sLogFileName)
{
$sLogFileFullPath = APPROOT
.DIRECTORY_SEPARATOR.'log'
.DIRECTORY_SEPARATOR.$sLogFileName;
/** @var \RotatingLogFileNameBuilder $oLogFileNameBuilder */
$oLogFileNameBuilder = new $sLogFileNameBuilder($sLogFileFullPath);
$oLogFileNameBuilder->ResetLastModifiedDateForFile();
$oLogFileNameBuilder->CheckAndRotateLogFile();
}
}
/**
* @inheritDoc
*/
public function GetNextOccurrence()
{
try
{
$sLogFileNameBuilder = $this->GetLogFileNameBuilderClassName();
}
catch (ProcessException $e)
{
return new DateTime('3000-01-01');
}
/** @var \RotatingLogFileNameBuilder $oLogFileNameBuilder */
$oLogFileNameBuilder = new $sLogFileNameBuilder();
return $oLogFileNameBuilder->GetCronProcessNextOccurrence(new DateTime());
}
/**
* @return string RotatingLogFileNameBuilder implementation configured
* @throws \ProcessException if the class is invalid
*/
private function GetLogFileNameBuilderClassName()
{
$sLogFileNameBuilder = MetaModel::GetConfig()->Get('log_filename_builder_impl');
if (is_a($sLogFileNameBuilder, RotatingLogFileNameBuilder::class, true))
{
return $sLogFileNameBuilder;
}
throw new ProcessException(self::class.' : The configured filename builder is invalid (log_filename_builder_impl="'.$sLogFileNameBuilder.'")');
}
}

View File

@@ -0,0 +1,80 @@
<?php
namespace Combodo\iTop\Test\UnitTest\Core;
use Combodo\iTop\Test\UnitTest\ItopTestCase;
use DailyRotatingLogFileNameBuilder;
use DateTime;
use WeeklyRotatingLogFileNameBuilder;
class LogFileNameBuilderTest extends ItopTestCase
{
public function ShouldRotateProvider()
{
return array(
'WEEKLY Same week' => array('WeeklyRotatingLogFileNameBuilder', '2020-02-01 00:00', '2020-02-01 00:00', false),
'WEEKLY 1 week diff, same month' => array('WeeklyRotatingLogFileNameBuilder', '2020-02-01 00:00', '2020-02-08 00:00', true),
'WEEKLY 2 weeks diff, same month' => array('WeeklyRotatingLogFileNameBuilder', '2020-02-01 00:00', '2020-02-15 00:00', true),
'WEEKLY 1 week diff, different month' => array('WeeklyRotatingLogFileNameBuilder', '2020-01-27 00:00', '2020-02-03 00:00', true),
'WEEKLY same week, different month' => array('WeeklyRotatingLogFileNameBuilder', '2020-01-27 00:00', '2020-02-02 00:00', false),
'WEEKLY 1 week diff, different year' => array('WeeklyRotatingLogFileNameBuilder', '2019-12-30 00:00', '2020-01-06 00:00', true),
'WEEKLY same week, different year' => array('WeeklyRotatingLogFileNameBuilder', '2019-12-30 00:00', '2020-01-05 00:00', true),
'DAILY Same day' => array('DailyRotatingLogFileNameBuilder', '2020-02-01 00:00', '2020-02-01 15:42', false),
'DAILY Same week, different day' => array('DailyRotatingLogFileNameBuilder', '2020-02-01 00:00', '2020-02-02 00:00', true),
'DAILY 1 week diff' => array('DailyRotatingLogFileNameBuilder', '2020-02-01 00:00', '2020-02-08 00:00', true),
);
}
/**
* @param string $sFileNameBuilderClass RotatingLogFileNameBuilder impl
* @param string $sDateModified format Y-m-d H:i
* @param string $sDateNow format Y-m-d H:i
* @param bool $bExpected
*
* @dataProvider ShouldRotateProvider
*/
public function testShouldRotate($sFileNameBuilderClass, $sDateModified, $sDateNow, $bExpected)
{
$oDateModified = DateTime::createFromFormat('Y-m-d H:i', $sDateModified);
$oDateNow = DateTime::createFromFormat('Y-m-d H:i', $sDateNow);
/** @var \RotatingLogFileNameBuilder $oFileBuilder */
$oFileBuilder = new $sFileNameBuilderClass();
$bShouldRotate = $oFileBuilder->ShouldRotate($oDateModified, $oDateNow);
$this->assertEquals($bExpected, $bShouldRotate);
}
public function CronNextOccurrenceProvider()
{
return array(
'DAILY morning' => array('DailyRotatingLogFileNameBuilder', '2020-02-01 05:00', '2020-02-02 00:00'),
'DAILY midnight' => array('DailyRotatingLogFileNameBuilder', '2020-02-01 00:00', '2020-02-02 00:00'),
'WEEKLY monday 12:42' => array('WeeklyRotatingLogFileNameBuilder', '2020-02-03 12:42', '2020-02-10 00:00'),
'WEEKLY monday 00:00' => array('WeeklyRotatingLogFileNameBuilder', '2020-02-03 00:00', '2020-02-10 00:00'),
'WEEKLY tuesday 12:42' => array('WeeklyRotatingLogFileNameBuilder', '2020-02-04 12:42', '2020-02-10 00:00'),
'WEEKLY sunday 12:42' => array('WeeklyRotatingLogFileNameBuilder', '2020-02-02 12:42', '2020-02-03 00:00'),
);
}
/**
* @param string $sFileNameBuilderClass RotatingLogFileNameBuilder impl
* @param string $sDateNow format Y-m-d H:i
* @param string $sExpectedOccurrence format Y-m-d H:i
*
* @dataProvider CronNextOccurrenceProvider
*/
public function testCronNextOccurrence($sFileNameBuilderClass, $sDateNow, $sExpectedOccurrence)
{
$oDateNow = DateTime::createFromFormat('Y-m-d H:i', $sDateNow);
/** @var \RotatingLogFileNameBuilder $oFileBuilder */
$oFileBuilder = new $sFileNameBuilderClass();
$oActualOccurrence = $oFileBuilder->GetCronProcessNextOccurrence($oDateNow);
$sActualOccurrence = $oActualOccurrence->format('Y-m-d H:i');
$this->assertEquals($sExpectedOccurrence, $sActualOccurrence);
}
}