2014-02-03 03:03:05 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# COMMON LOG MODULE
|
2014-02-03 03:03:05 +03:00
|
|
|
####################################################################################################################################
|
2016-04-14 15:30:54 +02:00
|
|
|
package pgBackRest::Common::Log;
|
2014-02-03 03:03:05 +03:00
|
|
|
|
|
|
|
use strict;
|
2015-03-03 07:57:20 +02:00
|
|
|
use warnings FATAL => qw(all);
|
2015-01-24 01:28:39 +02:00
|
|
|
use Carp qw(confess longmess);
|
2017-06-09 23:51:41 +02:00
|
|
|
use English '-no_match_vars';
|
2014-07-28 01:13:23 +03:00
|
|
|
|
2015-06-14 00:25:49 +02:00
|
|
|
use Exporter qw(import);
|
2015-08-29 20:20:46 +02:00
|
|
|
our @EXPORT = qw();
|
2014-02-15 03:56:28 +03:00
|
|
|
use Fcntl qw(:DEFAULT :flock);
|
2015-08-29 20:20:46 +02:00
|
|
|
use File::Basename qw(dirname);
|
|
|
|
use Scalar::Util qw(blessed reftype);
|
2015-06-14 00:25:49 +02:00
|
|
|
use Time::HiRes qw(gettimeofday usleep);
|
2014-06-07 18:51:27 +03:00
|
|
|
|
2016-04-14 15:30:54 +02:00
|
|
|
use pgBackRest::Common::Exception;
|
|
|
|
use pgBackRest::Common::String;
|
2014-02-03 03:03:05 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# Boolean constants
|
|
|
|
####################################################################################################################################
|
|
|
|
use constant true => 1;
|
|
|
|
push @EXPORT, qw(true);
|
|
|
|
use constant false => 0;
|
|
|
|
push @EXPORT, qw(false);
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# Log level constants
|
|
|
|
####################################################################################################################################
|
|
|
|
use constant TRACE => 'TRACE';
|
|
|
|
push @EXPORT, qw(TRACE);
|
|
|
|
use constant DEBUG => 'DEBUG';
|
|
|
|
push @EXPORT, qw(DEBUG);
|
2016-04-15 04:50:02 +02:00
|
|
|
use constant DETAIL => 'DETAIL';
|
|
|
|
push @EXPORT, qw(DETAIL);
|
2015-08-29 20:20:46 +02:00
|
|
|
use constant INFO => 'INFO';
|
|
|
|
push @EXPORT, qw(INFO);
|
|
|
|
use constant WARN => 'WARN';
|
|
|
|
push @EXPORT, qw(WARN);
|
2016-12-05 00:51:00 +02:00
|
|
|
use constant PROTOCOL => 'PROTOCOL';
|
|
|
|
push @EXPORT, qw(PROTOCOL);
|
2015-08-29 20:20:46 +02:00
|
|
|
use constant ERROR => 'ERROR';
|
|
|
|
push @EXPORT, qw(ERROR);
|
|
|
|
use constant ASSERT => 'ASSERT';
|
|
|
|
push @EXPORT, qw(ASSERT);
|
|
|
|
use constant OFF => 'OFF';
|
|
|
|
push @EXPORT, qw(OFF);
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# Log levels ranked by severity
|
|
|
|
####################################################################################################################################
|
|
|
|
my %oLogLevelRank;
|
2014-02-15 03:56:28 +03:00
|
|
|
|
2016-12-05 00:51:00 +02:00
|
|
|
$oLogLevelRank{TRACE}{rank} = 8;
|
|
|
|
$oLogLevelRank{DEBUG}{rank} = 7;
|
|
|
|
$oLogLevelRank{DETAIL}{rank} = 6;
|
|
|
|
$oLogLevelRank{INFO}{rank} = 5;
|
|
|
|
$oLogLevelRank{WARN}{rank} = 4;
|
|
|
|
$oLogLevelRank{PROTOCOL}{rank} = 3;
|
2016-10-05 15:09:30 +02:00
|
|
|
$oLogLevelRank{ERROR}{rank} = 2;
|
|
|
|
$oLogLevelRank{ASSERT}{rank} = 1;
|
2014-02-14 01:11:53 +03:00
|
|
|
$oLogLevelRank{OFF}{rank} = 0;
|
2014-02-13 21:54:43 +03:00
|
|
|
|
2014-07-28 01:13:23 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# Module globals
|
2014-07-28 01:13:23 +03:00
|
|
|
####################################################################################################################################
|
2016-09-14 23:40:13 +02:00
|
|
|
my $hLogFile = undef;
|
|
|
|
my $strLogFileCache = undef;
|
|
|
|
|
2016-10-05 15:09:30 +02:00
|
|
|
my $strLogLevelFile = OFF;
|
|
|
|
my $strLogLevelConsole = OFF;
|
2016-12-04 01:01:17 +02:00
|
|
|
my $strLogLevelStdErr = WARN;
|
2017-02-05 17:59:49 +02:00
|
|
|
my $bLogTimestamp = true;
|
2014-07-28 01:13:23 +03:00
|
|
|
|
2019-04-08 00:12:07 +02:00
|
|
|
# Size of the process id log field
|
|
|
|
my $iLogProcessSize = 2;
|
|
|
|
|
2017-02-05 17:37:54 +02:00
|
|
|
# Flags to limit banner printing until there is actual output
|
|
|
|
my $bLogFileExists;
|
|
|
|
my $bLogFileFirst;
|
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
# Allow log to be globally enabled or disabled with logEnable() and logDisable()
|
|
|
|
my $bLogDisable = 0;
|
|
|
|
|
2017-09-01 01:15:44 +02:00
|
|
|
# Allow errors to be logged as warnings
|
|
|
|
my $bLogWarnOnError = 0;
|
|
|
|
|
2017-10-21 20:11:33 +02:00
|
|
|
# Store the last logged error
|
|
|
|
my $oErrorLast;
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# Test globals
|
2014-07-28 01:13:23 +03:00
|
|
|
my $bTest = false;
|
2015-01-25 19:20:12 +02:00
|
|
|
my $fTestDelay;
|
2015-10-08 17:43:56 +02:00
|
|
|
my $oTestPoint;
|
2014-07-28 01:13:23 +03:00
|
|
|
|
2015-01-27 18:44:23 +02:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# Test constants
|
2015-01-27 18:44:23 +02:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
use constant TEST => 'TEST';
|
|
|
|
push @EXPORT, qw(TEST);
|
|
|
|
use constant TEST_ENCLOSE => 'PgBaCkReStTeSt';
|
|
|
|
push @EXPORT, qw(TEST_ENCLOSE);
|
2015-01-27 18:44:23 +02:00
|
|
|
|
2015-10-08 17:43:56 +02:00
|
|
|
use constant TEST_MANIFEST_BUILD => 'MANIFEST-BUILD';
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(TEST_MANIFEST_BUILD);
|
2015-10-08 17:43:56 +02:00
|
|
|
use constant TEST_BACKUP_RESUME => 'BACKUP-RESUME';
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(TEST_BACKUP_RESUME);
|
2015-10-08 17:43:56 +02:00
|
|
|
use constant TEST_BACKUP_NORESUME => 'BACKUP-NORESUME';
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(TEST_BACKUP_NORESUME);
|
2015-10-08 17:43:56 +02:00
|
|
|
use constant TEST_BACKUP_START => 'BACKUP-START';
|
|
|
|
push @EXPORT, qw(TEST_BACKUP_START);
|
2016-09-14 23:37:07 +02:00
|
|
|
use constant TEST_BACKUP_STOP => 'BACKUP-STOP';
|
|
|
|
push @EXPORT, qw(TEST_BACKUP_STOP);
|
2015-12-24 17:32:25 +02:00
|
|
|
use constant TEST_KEEP_ALIVE => 'KEEP_ALIVE';
|
|
|
|
push @EXPORT, qw(TEST_KEEP_ALIVE);
|
2015-10-08 17:43:56 +02:00
|
|
|
use constant TEST_ARCHIVE_PUSH_ASYNC_START => 'ARCHIVE-PUSH-ASYNC-START';
|
|
|
|
push @EXPORT, qw(TEST_ARCHIVE_PUSH_ASYNC_START);
|
2015-01-27 18:44:23 +02:00
|
|
|
|
2014-02-03 03:03:05 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# logFileSet - set the file messages will be logged to
|
2014-02-03 03:03:05 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
sub logFileSet
|
2014-02-03 03:03:05 +03:00
|
|
|
{
|
2017-08-25 22:47:47 +02:00
|
|
|
my $oStorage = shift;
|
2015-08-29 20:20:46 +02:00
|
|
|
my $strFile = shift;
|
2018-03-12 16:55:58 +02:00
|
|
|
my $bLogFileFirstParam = shift;
|
2014-06-04 05:02:56 +03:00
|
|
|
|
2015-12-23 17:48:33 +02:00
|
|
|
# Only open the log file if file logging is enabled
|
|
|
|
if ($strLogLevelFile ne OFF)
|
2014-02-03 03:03:05 +03:00
|
|
|
{
|
2017-08-25 22:47:47 +02:00
|
|
|
$oStorage->pathCreate(dirname($strFile), {strMode => '0770', bIgnoreExists => true, bCreateParent => true});
|
2014-02-03 03:03:05 +03:00
|
|
|
|
2016-04-14 15:30:54 +02:00
|
|
|
$strFile .= '.log';
|
2017-02-05 17:37:54 +02:00
|
|
|
$bLogFileExists = -e $strFile ? true : false;
|
2018-03-12 16:55:58 +02:00
|
|
|
$bLogFileFirst = defined($bLogFileFirstParam) ? $bLogFileFirstParam : false;
|
2014-02-03 03:03:05 +03:00
|
|
|
|
2017-06-09 23:51:41 +02:00
|
|
|
if (!sysopen($hLogFile, $strFile, O_WRONLY | O_CREAT | O_APPEND, oct('0660')))
|
|
|
|
{
|
|
|
|
logErrorResult(ERROR_FILE_OPEN, "unable to open log file '${strFile}'", $OS_ERROR);
|
|
|
|
}
|
2014-02-03 03:03:05 +03:00
|
|
|
|
2016-09-14 23:40:13 +02:00
|
|
|
# Write out anything that was cached before the file was opened
|
|
|
|
if (defined($strLogFileCache))
|
|
|
|
{
|
2017-02-05 17:37:54 +02:00
|
|
|
logBanner();
|
2016-09-14 23:40:13 +02:00
|
|
|
syswrite($hLogFile, $strLogFileCache);
|
|
|
|
undef($strLogFileCache);
|
|
|
|
}
|
2015-12-23 17:48:33 +02:00
|
|
|
}
|
2014-02-03 03:03:05 +03:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(logFileSet);
|
2015-01-25 19:20:12 +02:00
|
|
|
|
2017-02-05 17:37:54 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logBanner
|
|
|
|
#
|
|
|
|
# Output a banner on the first log entry written to a file
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logBanner
|
|
|
|
{
|
|
|
|
if ($bLogFileFirst)
|
|
|
|
{
|
|
|
|
if ($bLogFileExists)
|
|
|
|
{
|
|
|
|
syswrite($hLogFile, "\n");
|
|
|
|
}
|
|
|
|
|
|
|
|
syswrite($hLogFile, "-------------------PROCESS START-------------------\n");
|
|
|
|
}
|
|
|
|
|
|
|
|
$bLogFileFirst = false;
|
|
|
|
}
|
|
|
|
|
2014-02-05 18:40:49 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# logLevelSet - set the log level for file and console
|
2014-02-05 18:40:49 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
sub logLevelSet
|
2014-02-05 18:40:49 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
my $strLevelFileParam = shift;
|
|
|
|
my $strLevelConsoleParam = shift;
|
2016-12-04 01:01:17 +02:00
|
|
|
my $strLevelStdErrParam = shift;
|
2017-02-05 17:59:49 +02:00
|
|
|
my $bLogTimestampParam = shift;
|
2019-04-08 00:12:07 +02:00
|
|
|
my $iLogProcessMax = shift;
|
2014-06-04 05:02:56 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
if (defined($strLevelFileParam))
|
2014-02-05 18:40:49 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
if (!defined($oLogLevelRank{uc($strLevelFileParam)}{rank}))
|
2014-02-05 18:40:49 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
confess &log(ERROR, "file log level ${strLevelFileParam} does not exist");
|
2014-02-05 18:40:49 +03:00
|
|
|
}
|
2014-06-04 05:02:56 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
$strLogLevelFile = uc($strLevelFileParam);
|
2014-02-13 21:54:43 +03:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
if (defined($strLevelConsoleParam))
|
2014-02-13 21:54:43 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
if (!defined($oLogLevelRank{uc($strLevelConsoleParam)}{rank}))
|
|
|
|
{
|
|
|
|
confess &log(ERROR, "console log level ${strLevelConsoleParam} does not exist");
|
|
|
|
}
|
2014-02-13 21:54:43 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
$strLogLevelConsole = uc($strLevelConsoleParam);
|
2014-02-13 21:54:43 +03:00
|
|
|
}
|
2016-10-05 15:09:30 +02:00
|
|
|
|
2016-12-04 01:01:17 +02:00
|
|
|
if (defined($strLevelStdErrParam))
|
2016-10-05 15:09:30 +02:00
|
|
|
{
|
2016-12-04 01:01:17 +02:00
|
|
|
if (!defined($oLogLevelRank{uc($strLevelStdErrParam)}{rank}))
|
2016-10-05 15:09:30 +02:00
|
|
|
{
|
2016-12-04 01:01:17 +02:00
|
|
|
confess &log(ERROR, "stdout log level ${strLevelStdErrParam} does not exist");
|
2016-10-05 15:09:30 +02:00
|
|
|
}
|
|
|
|
|
2016-12-04 01:01:17 +02:00
|
|
|
$strLogLevelStdErr = uc($strLevelStdErrParam);
|
2016-10-05 15:09:30 +02:00
|
|
|
}
|
2017-02-05 17:59:49 +02:00
|
|
|
|
|
|
|
if (defined($bLogTimestampParam))
|
|
|
|
{
|
|
|
|
$bLogTimestamp = $bLogTimestampParam;
|
|
|
|
}
|
2019-04-08 00:12:07 +02:00
|
|
|
|
|
|
|
if (defined($iLogProcessMax))
|
|
|
|
{
|
|
|
|
$iLogProcessSize = $iLogProcessMax > 99 ? 3 : 2;
|
|
|
|
}
|
2014-02-13 21:54:43 +03:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(logLevelSet);
|
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logDisable
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logDisable
|
|
|
|
{
|
|
|
|
$bLogDisable++;
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logDisable);
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# logEnable
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logEnable
|
|
|
|
{
|
|
|
|
$bLogDisable--;
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logEnable);
|
|
|
|
|
2017-09-01 01:15:44 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logWarnOnErrorDisable
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logWarnOnErrorDisable
|
|
|
|
{
|
|
|
|
$bLogWarnOnError--;
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logWarnOnErrorDisable);
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# logWarnOnErrorEnable - when an error is thrown, log it as a warning instead
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logWarnOnErrorEnable
|
|
|
|
{
|
|
|
|
$bLogWarnOnError++;
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logWarnOnErrorEnable);
|
|
|
|
|
2014-02-03 03:03:05 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# logDebugParam
|
|
|
|
#
|
|
|
|
# Log parameters passed to functions.
|
2014-02-03 03:03:05 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
use constant DEBUG_PARAM => '()';
|
|
|
|
|
|
|
|
sub logDebugParam
|
2014-02-03 03:03:05 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
my $strFunction = shift;
|
|
|
|
my $oyParamRef = shift;
|
2014-06-04 05:02:56 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
return logDebugProcess($strFunction, DEBUG_PARAM, undef, $oyParamRef, @_);
|
|
|
|
}
|
2014-06-04 05:02:56 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(logDebugParam);
|
2015-01-03 23:49:26 +02:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logDebugReturn
|
|
|
|
#
|
|
|
|
# Log values returned from functions.
|
|
|
|
####################################################################################################################################
|
|
|
|
use constant DEBUG_RETURN => '=>';
|
2014-02-03 03:03:05 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
sub logDebugReturn
|
|
|
|
{
|
|
|
|
my $strFunction = shift;
|
|
|
|
|
|
|
|
return logDebugProcess($strFunction, DEBUG_RETURN, undef, undef, @_);
|
2014-08-13 03:00:52 +03:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(logDebugReturn);
|
|
|
|
|
2014-08-13 03:00:52 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# logDebugMisc
|
|
|
|
#
|
|
|
|
# Log misc values and details during execution.
|
2014-08-13 03:00:52 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
use constant DEBUG_MISC => '';
|
|
|
|
|
|
|
|
sub logDebugMisc
|
2014-08-13 03:00:52 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
my $strFunction = shift;
|
|
|
|
my $strDetail = shift;
|
|
|
|
|
|
|
|
return logDebugProcess($strFunction, DEBUG_MISC, $strDetail, undef, @_);
|
2014-02-13 21:54:43 +03:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(logDebugMisc);
|
|
|
|
|
2014-02-13 21:54:43 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# logDebugProcess
|
2014-02-13 21:54:43 +03:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
sub logDebugProcess
|
2014-02-13 21:54:43 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
my $strFunction = shift;
|
|
|
|
my $strType = shift;
|
|
|
|
my $strDetail = shift;
|
|
|
|
my $oyParamRef = shift;
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
my $iIndex = 0;
|
|
|
|
my $oParamHash = {};
|
|
|
|
my @oyResult;
|
|
|
|
my $bLogTrace = true;
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
if ($strType eq DEBUG_PARAM)
|
2014-02-13 21:54:43 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
push @oyResult, $strFunction;
|
2014-02-13 21:54:43 +03:00
|
|
|
}
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# Process each parameter hash
|
|
|
|
my $oParam = shift;
|
2017-04-05 03:17:19 +02:00
|
|
|
my $bOptionalBlock = false;
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2016-08-11 23:32:28 +02:00
|
|
|
# Strip the package name off strFunction if it's pgBackRest
|
|
|
|
$strFunction =~ s/^pgBackRest[^\:]*\:\://;
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
while (defined($oParam))
|
2014-02-13 21:54:43 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
my $strParamName = $$oParam{name};
|
2017-04-05 03:17:19 +02:00
|
|
|
my $bParamOptional = defined($oParam->{optional}) && $oParam->{optional};
|
|
|
|
my $bParamRequired = !defined($oParam->{required}) || $oParam->{required};
|
2015-08-29 20:20:46 +02:00
|
|
|
my $oValue;
|
2014-02-13 21:54:43 +03:00
|
|
|
|
2017-10-24 18:35:36 +02:00
|
|
|
# Should the param be redacted?
|
|
|
|
$oParamHash->{$strParamName}{redact} = $oParam->{redact} ? true : false;
|
|
|
|
|
2017-04-05 03:17:19 +02:00
|
|
|
# If param is optional then the optional block has been entered
|
|
|
|
if ($bParamOptional)
|
|
|
|
{
|
|
|
|
if (defined($oParam->{required}))
|
|
|
|
{
|
|
|
|
confess &log(ASSERT, "cannot define 'required' for optional parameter '${strParamName}'");
|
|
|
|
}
|
|
|
|
|
|
|
|
$bParamRequired = false;
|
|
|
|
$bOptionalBlock = true;
|
|
|
|
}
|
|
|
|
|
|
|
|
# Don't allow non-optional parameters once optional block has started
|
|
|
|
if ($bParamOptional != $bOptionalBlock)
|
|
|
|
{
|
|
|
|
confess &log(ASSERT, "non-optional parameter '${strParamName}' invalid after optional parameters");
|
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# Push the return value into the return value array
|
|
|
|
if ($strType eq DEBUG_PARAM)
|
|
|
|
{
|
2017-04-05 03:17:19 +02:00
|
|
|
if ($bParamOptional)
|
2015-08-29 20:20:46 +02:00
|
|
|
{
|
2017-04-05 03:17:19 +02:00
|
|
|
$oValue = $$oyParamRef[$iIndex]->{$strParamName};
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
$oValue = $$oyParamRef[$iIndex];
|
|
|
|
}
|
|
|
|
|
|
|
|
if (defined($oValue))
|
|
|
|
{
|
|
|
|
push(@oyResult, $oValue);
|
2015-08-29 20:20:46 +02:00
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
push(@oyResult, $${oParam}{default});
|
|
|
|
$$oParamHash{$strParamName}{default} = true;
|
|
|
|
}
|
2014-07-28 01:13:23 +03:00
|
|
|
|
2017-04-10 23:23:39 +02:00
|
|
|
$oValue = $oyResult[-1];
|
2014-07-28 01:13:23 +03:00
|
|
|
|
2017-04-05 03:17:19 +02:00
|
|
|
if (!defined($oValue) && $bParamRequired)
|
2015-08-29 20:20:46 +02:00
|
|
|
{
|
|
|
|
confess &log(ASSERT, "${strParamName} is required in ${strFunction}");
|
|
|
|
}
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
if (ref($$oParam{value}) eq 'ARRAY')
|
|
|
|
{
|
|
|
|
if (defined($$oParam{ref}) && $$oParam{ref})
|
|
|
|
{
|
|
|
|
push(@oyResult, $$oParam{value});
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
push(@oyResult, @{$$oParam{value}});
|
|
|
|
}
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
push(@oyResult, $$oParam{value});
|
|
|
|
}
|
2014-09-18 22:18:52 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
$oValue = $$oParam{value};
|
|
|
|
}
|
2014-07-28 01:13:23 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
if (!defined($$oParam{log}) || $$oParam{log})
|
|
|
|
{
|
|
|
|
# If the parameter is a hash but not blessed then represent it as a string
|
2016-04-14 01:05:31 +02:00
|
|
|
# ??? This should go away once the inputs to logDebug can be changed
|
2015-08-29 20:20:46 +02:00
|
|
|
if (ref($oValue) eq 'HASH' && !blessed($oValue))
|
|
|
|
{
|
|
|
|
$$oParamHash{$strParamName}{value} = '[hash]';
|
|
|
|
}
|
|
|
|
# Else log the parameter value exactly
|
|
|
|
else
|
|
|
|
{
|
|
|
|
$$oParamHash{$strParamName}{value} = $oValue;
|
|
|
|
}
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# There are certain return values that it's wasteful to generate debug logging for
|
|
|
|
if (!($strParamName eq 'self') &&
|
|
|
|
(!defined($$oParam{trace}) || !$$oParam{trace}))
|
|
|
|
{
|
|
|
|
$bLogTrace = false;
|
|
|
|
}
|
2014-06-04 04:22:07 +03:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# Get the next parameter hash
|
|
|
|
$oParam = shift;
|
2017-04-05 03:17:19 +02:00
|
|
|
|
|
|
|
if (!$bParamOptional)
|
|
|
|
{
|
|
|
|
$iIndex++;
|
|
|
|
}
|
2014-02-14 01:11:53 +03:00
|
|
|
}
|
2014-02-03 03:03:05 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
if (defined($strDetail) && $iIndex == 0)
|
2014-02-14 01:11:53 +03:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
$bLogTrace = false;
|
2014-06-04 04:22:07 +03:00
|
|
|
}
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
logDebugOut($strFunction, $strType, $strDetail, $oParamHash, $bLogTrace ? TRACE : DEBUG);
|
2014-08-10 22:02:14 +03:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# If there are one or zero return values then just return a scalar (this will be undef if there are no return values)
|
|
|
|
if (@oyResult == 1)
|
|
|
|
{
|
|
|
|
return $oyResult[0];
|
|
|
|
}
|
|
|
|
|
|
|
|
# Else return an array containing return values
|
|
|
|
return @oyResult;
|
2014-08-10 22:02:14 +03:00
|
|
|
}
|
|
|
|
|
2016-12-10 16:15:20 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logDebugBuild
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logDebugBuild
|
|
|
|
{
|
|
|
|
my $strValue = shift;
|
|
|
|
|
|
|
|
my $rResult;
|
|
|
|
|
|
|
|
# Value is undefined
|
|
|
|
if (!defined($strValue))
|
|
|
|
{
|
|
|
|
$rResult = \'[undef]';
|
|
|
|
}
|
|
|
|
# Value is not a ref, but return it as a ref for efficiency
|
|
|
|
elsif (!ref($strValue))
|
|
|
|
{
|
|
|
|
$rResult = \$strValue;
|
|
|
|
}
|
|
|
|
# Value is a hash
|
|
|
|
elsif (ref($strValue) eq 'HASH')
|
|
|
|
{
|
|
|
|
my $strValueHash;
|
|
|
|
|
|
|
|
for my $strSubValue (sort(keys(%{$strValue})))
|
|
|
|
{
|
|
|
|
$strValueHash .=
|
|
|
|
(defined($strValueHash) ? ', ' : '{') . "${strSubValue} => " . ${logDebugBuild($strValue->{$strSubValue})};
|
|
|
|
}
|
|
|
|
|
|
|
|
$rResult = \(defined($strValueHash) ? $strValueHash . '}' : '{}');
|
|
|
|
}
|
|
|
|
# Value is an array
|
|
|
|
elsif (ref($strValue) eq 'ARRAY')
|
|
|
|
{
|
|
|
|
my $strValueArray;
|
|
|
|
|
|
|
|
for my $strSubValue (@{$strValue})
|
|
|
|
{
|
|
|
|
$strValueArray .= (defined($strValueArray) ? ', ' : '(') . ${logDebugBuild($strSubValue)};
|
|
|
|
}
|
|
|
|
|
|
|
|
$rResult = \(defined($strValueArray) ? $strValueArray . ')' : '()');
|
|
|
|
}
|
|
|
|
# Else some other type ??? For the moment this is forced to object to not make big log changes
|
|
|
|
else
|
|
|
|
{
|
|
|
|
$rResult = \('[object]');
|
|
|
|
}
|
|
|
|
|
|
|
|
return $rResult;
|
|
|
|
}
|
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
push @EXPORT, qw(logDebugBuild);
|
|
|
|
|
2015-06-17 21:33:58 +02:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# logDebugOut
|
2015-06-17 21:33:58 +02:00
|
|
|
####################################################################################################################################
|
2015-08-05 14:43:41 +02:00
|
|
|
use constant DEBUG_STRING_MAX_LEN => 1024;
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
sub logDebugOut
|
2015-06-17 21:33:58 +02:00
|
|
|
{
|
|
|
|
my $strFunction = shift;
|
|
|
|
my $strType = shift;
|
|
|
|
my $strMessage = shift;
|
|
|
|
my $oParamHash = shift;
|
|
|
|
my $strLevel = shift;
|
2015-06-17 21:40:12 +02:00
|
|
|
|
2015-06-17 21:33:58 +02:00
|
|
|
$strLevel = defined($strLevel) ? $strLevel : DEBUG;
|
|
|
|
|
|
|
|
if ($oLogLevelRank{$strLevel}{rank} <= $oLogLevelRank{$strLogLevelConsole}{rank} ||
|
2016-12-04 00:34:51 +02:00
|
|
|
$oLogLevelRank{$strLevel}{rank} <= $oLogLevelRank{$strLogLevelFile}{rank} ||
|
2016-12-04 01:01:17 +02:00
|
|
|
$oLogLevelRank{$strLevel}{rank} <= $oLogLevelRank{$strLogLevelStdErr}{rank})
|
2015-06-17 21:33:58 +02:00
|
|
|
{
|
|
|
|
if (defined($oParamHash))
|
|
|
|
{
|
|
|
|
my $strParamSet;
|
2015-06-17 21:40:12 +02:00
|
|
|
|
2015-06-21 18:06:13 +02:00
|
|
|
foreach my $strParam (sort(keys(%$oParamHash)))
|
2015-06-17 21:33:58 +02:00
|
|
|
{
|
|
|
|
if (defined($strParamSet))
|
|
|
|
{
|
|
|
|
$strParamSet .= ', ';
|
|
|
|
}
|
2015-06-17 21:40:12 +02:00
|
|
|
|
2016-12-10 16:15:20 +02:00
|
|
|
my $strValueRef = defined($oParamHash->{$strParam}{value}) ? logDebugBuild($oParamHash->{$strParam}{value}) : undef;
|
|
|
|
my $bDefault =
|
|
|
|
defined($$strValueRef) && defined($$oParamHash{$strParam}{default}) ? $$oParamHash{$strParam}{default} : false;
|
2015-08-05 14:43:41 +02:00
|
|
|
|
2017-10-24 18:35:36 +02:00
|
|
|
$strParamSet .=
|
|
|
|
"${strParam} = " .
|
|
|
|
($oParamHash->{$strParam}{redact} && defined($$strValueRef) ? '<redacted>' :
|
|
|
|
($bDefault ? '<' : '') .
|
|
|
|
(defined($$strValueRef) ?
|
|
|
|
($strParam =~ /^(b|is)/ ? ($$strValueRef ? 'true' : 'false'):
|
|
|
|
(length($$strValueRef) > DEBUG_STRING_MAX_LEN ?
|
|
|
|
substr($$strValueRef, 0, DEBUG_STRING_MAX_LEN) . ' ... <truncated>':
|
|
|
|
$$strValueRef)) : '[undef]') .
|
|
|
|
($bDefault ? '>' : ''));
|
2015-06-17 21:33:58 +02:00
|
|
|
}
|
2015-06-17 21:40:12 +02:00
|
|
|
|
2015-06-17 21:33:58 +02:00
|
|
|
if (defined($strMessage))
|
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
$strMessage = $strMessage . (defined($strParamSet) ? ": ${strParamSet}" : '');
|
2015-06-17 21:33:58 +02:00
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
$strMessage = $strParamSet;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
&log($strLevel, "${strFunction}${strType}" . (defined($strMessage) ? ": $strMessage" : ''));
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2016-12-04 01:01:17 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logException
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logException
|
|
|
|
{
|
|
|
|
my $oException = shift;
|
|
|
|
|
|
|
|
return &log($oException->level(), $oException->message(), $oException->code(), undef, undef, undef, $oException->extra());
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logException);
|
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logErrorResult
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logErrorResult
|
|
|
|
{
|
|
|
|
my $iCode = shift;
|
|
|
|
my $strMessage = shift;
|
2017-02-14 02:59:14 +02:00
|
|
|
my $strResult = shift;
|
2017-01-27 16:42:30 +02:00
|
|
|
|
2017-10-21 20:11:33 +02:00
|
|
|
confess &log(ERROR, $strMessage . (defined($strResult) ? ': ' . trim($strResult) : ''), $iCode);
|
2017-01-27 16:42:30 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logErrorResult);
|
|
|
|
|
2014-02-14 01:11:53 +03:00
|
|
|
####################################################################################################################################
|
|
|
|
# LOG - log messages
|
|
|
|
####################################################################################################################################
|
2014-02-03 03:03:05 +03:00
|
|
|
sub log
|
|
|
|
{
|
|
|
|
my $strLevel = shift;
|
|
|
|
my $strMessage = shift;
|
2014-06-07 18:51:27 +03:00
|
|
|
my $iCode = shift;
|
2014-09-30 22:51:08 +03:00
|
|
|
my $bSuppressLog = shift;
|
2016-01-09 15:21:53 +02:00
|
|
|
my $iIndent = shift;
|
2016-09-06 15:35:02 +02:00
|
|
|
my $iProcessId = shift;
|
2016-12-04 01:01:17 +02:00
|
|
|
my $rExtra = shift;
|
2014-06-07 18:51:27 +03:00
|
|
|
|
2014-09-30 22:51:08 +03:00
|
|
|
# Set defaults
|
|
|
|
$bSuppressLog = defined($bSuppressLog) ? $bSuppressLog : false;
|
|
|
|
|
2016-12-04 01:01:17 +02:00
|
|
|
# Initialize rExtra
|
|
|
|
if (!defined($rExtra))
|
|
|
|
{
|
|
|
|
$rExtra =
|
|
|
|
{
|
|
|
|
bLogFile => false,
|
|
|
|
bLogConsole => false,
|
|
|
|
};
|
|
|
|
}
|
|
|
|
|
2014-09-30 22:51:08 +03:00
|
|
|
# Set operational variables
|
2014-06-07 18:51:27 +03:00
|
|
|
my $strMessageFormat = $strMessage;
|
2017-09-01 01:15:44 +02:00
|
|
|
my $iLogLevelRank = $oLogLevelRank{$strLevel}{rank};
|
2014-02-03 03:03:05 +03:00
|
|
|
|
2014-08-10 22:02:14 +03:00
|
|
|
# If test message
|
2014-08-10 01:35:55 +03:00
|
|
|
if ($strLevel eq TEST)
|
2014-07-28 01:13:23 +03:00
|
|
|
{
|
2015-10-08 17:43:56 +02:00
|
|
|
if (!defined($oTestPoint) || !defined($$oTestPoint{lc($strMessage)}))
|
|
|
|
{
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
2014-08-10 01:35:55 +03:00
|
|
|
$iLogLevelRank = $oLogLevelRank{TRACE}{rank} + 1;
|
2014-07-28 01:13:23 +03:00
|
|
|
$strMessageFormat = TEST_ENCLOSE . '-' . $strMessageFormat . '-' . TEST_ENCLOSE;
|
|
|
|
}
|
2014-08-10 22:02:14 +03:00
|
|
|
# Else level rank must be valid
|
2014-08-10 01:35:55 +03:00
|
|
|
elsif (!defined($iLogLevelRank))
|
2014-02-14 01:11:53 +03:00
|
|
|
{
|
|
|
|
confess &log(ASSERT, "log level ${strLevel} does not exist");
|
|
|
|
}
|
2014-06-04 05:02:56 +03:00
|
|
|
|
2014-08-10 22:02:14 +03:00
|
|
|
# If message was undefined then set default message
|
2014-06-07 18:51:27 +03:00
|
|
|
if (!defined($strMessageFormat))
|
2014-02-03 03:03:05 +03:00
|
|
|
{
|
2014-09-16 15:21:29 +03:00
|
|
|
$strMessageFormat = '(undefined)';
|
2014-02-03 03:03:05 +03:00
|
|
|
}
|
|
|
|
|
2016-09-04 15:25:20 +02:00
|
|
|
# Set the error code
|
|
|
|
if ($strLevel eq ASSERT)
|
|
|
|
{
|
|
|
|
$iCode = ERROR_ASSERT;
|
|
|
|
}
|
|
|
|
elsif ($strLevel eq ERROR && !defined($iCode))
|
|
|
|
{
|
|
|
|
$iCode = ERROR_UNKNOWN;
|
|
|
|
}
|
|
|
|
|
2017-04-12 18:41:34 +02:00
|
|
|
$strMessageFormat = (defined($iCode) ? sprintf('[%03d]: ', $iCode) : '') . $strMessageFormat;
|
2015-01-24 01:28:39 +02:00
|
|
|
|
2014-08-10 22:02:14 +03:00
|
|
|
# Indent subsequent lines of the message if it has more than one line - makes the log more readable
|
2016-01-09 15:21:53 +02:00
|
|
|
if (defined($iIndent))
|
|
|
|
{
|
|
|
|
my $strIndent = ' ' x $iIndent;
|
|
|
|
$strMessageFormat =~ s/\n/\n${strIndent}/g;
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
2017-02-06 02:58:52 +02:00
|
|
|
# Indent subsequent message lines so they align
|
|
|
|
$bLogTimestamp ?
|
|
|
|
$strMessageFormat =~ s/\n/\n /g :
|
|
|
|
$strMessageFormat =~ s/\n/\n /g
|
2016-01-09 15:21:53 +02:00
|
|
|
}
|
2015-05-29 02:52:42 +02:00
|
|
|
|
2017-02-06 02:58:52 +02:00
|
|
|
# Indent TRACE and debug levels so they are distinct from normal messages
|
2014-08-10 01:35:55 +03:00
|
|
|
if ($strLevel eq TRACE || $strLevel eq TEST)
|
2014-02-13 21:54:43 +03:00
|
|
|
{
|
2015-05-29 02:52:42 +02:00
|
|
|
$strMessageFormat =~ s/\n/\n /g;
|
2014-09-16 15:21:29 +03:00
|
|
|
$strMessageFormat = ' ' . $strMessageFormat;
|
2014-02-13 21:54:43 +03:00
|
|
|
}
|
2014-08-10 01:35:55 +03:00
|
|
|
elsif ($strLevel eq DEBUG)
|
2014-02-13 21:54:43 +03:00
|
|
|
{
|
2015-05-29 02:52:42 +02:00
|
|
|
$strMessageFormat =~ s/\n/\n /g;
|
2014-09-16 15:21:29 +03:00
|
|
|
$strMessageFormat = ' ' . $strMessageFormat;
|
2014-02-13 21:54:43 +03:00
|
|
|
}
|
|
|
|
|
2014-08-10 22:02:14 +03:00
|
|
|
# Format the message text
|
|
|
|
my ($sec, $min, $hour, $mday, $mon, $year, $wday, $yday, $isdst) = localtime(time);
|
|
|
|
|
2017-09-01 01:15:44 +02:00
|
|
|
# If logging warnings as errors then change the display level and rank. These will be used to determine if the message will be
|
|
|
|
# displayed or not.
|
2017-09-19 16:03:53 +02:00
|
|
|
my $strDisplayLevel = ($bLogWarnOnError && $strLevel eq ERROR ? WARN : $strLevel);
|
|
|
|
my $iLogDisplayLevelRank = ($bLogWarnOnError && $strLevel eq ERROR ? $oLogLevelRank{$strDisplayLevel}{rank} : $iLogLevelRank);
|
2017-09-01 01:15:44 +02:00
|
|
|
|
2016-09-06 15:35:02 +02:00
|
|
|
$strMessageFormat =
|
2017-02-05 17:59:49 +02:00
|
|
|
($bLogTimestamp ? timestampFormat() . sprintf('.%03d ', (gettimeofday() - int(gettimeofday())) * 1000) : '') .
|
2019-04-08 00:12:07 +02:00
|
|
|
sprintf('P%0*d', $iLogProcessSize, defined($iProcessId) ? $iProcessId : 0) .
|
2017-09-01 01:15:44 +02:00
|
|
|
(' ' x (7 - length($strDisplayLevel))) . "${strDisplayLevel}: ${strMessageFormat}\n";
|
2014-02-13 21:54:43 +03:00
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
# Skip output if disabled
|
|
|
|
if (!$bLogDisable)
|
2016-10-05 15:09:30 +02:00
|
|
|
{
|
2017-09-01 01:15:44 +02:00
|
|
|
# Output to stderr if configured log level setting rank is greater than the display level rank.
|
|
|
|
if (!$rExtra->{bLogConsole} && $iLogDisplayLevelRank <= $oLogLevelRank{$strLogLevelStdErr}{rank})
|
2016-12-05 00:51:00 +02:00
|
|
|
{
|
2017-01-27 16:42:30 +02:00
|
|
|
if ($strLogLevelStdErr ne PROTOCOL)
|
|
|
|
{
|
2017-09-01 01:15:44 +02:00
|
|
|
syswrite(*STDERR, $strDisplayLevel . (defined($iCode) ? sprintf(' [%03d]: ', $iCode) : '') . ': ');
|
2017-01-27 16:42:30 +02:00
|
|
|
}
|
2016-12-05 00:51:00 +02:00
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
syswrite(*STDERR, "${strMessage}\n");
|
|
|
|
$rExtra->{bLogConsole} = true;
|
2014-09-30 22:51:08 +03:00
|
|
|
}
|
2017-09-01 01:15:44 +02:00
|
|
|
# Else output to stdout if configured log level setting rank is greater than the display level rank or test flag is set.
|
|
|
|
elsif (!$rExtra->{bLogConsole} && $iLogDisplayLevelRank <= $oLogLevelRank{$strLogLevelConsole}{rank} ||
|
2017-01-27 16:42:30 +02:00
|
|
|
$bTest && $strLevel eq TEST)
|
2014-08-10 22:02:14 +03:00
|
|
|
{
|
2017-01-27 16:42:30 +02:00
|
|
|
if (!$bSuppressLog)
|
|
|
|
{
|
|
|
|
syswrite(*STDOUT, $strMessageFormat);
|
2017-06-09 23:51:41 +02:00
|
|
|
|
|
|
|
# This is here for debugging purposes - it's not clear how best to make it into a switch
|
|
|
|
# if ($strLevel eq ASSERT || $strLevel eq ERROR)
|
|
|
|
# {
|
|
|
|
# my $strStackTrace = longmess() . "\n";
|
|
|
|
# $strStackTrace =~ s/\n/\n /g;
|
|
|
|
# syswrite(*STDOUT, $strStackTrace);
|
|
|
|
# }
|
2017-01-27 16:42:30 +02:00
|
|
|
}
|
2016-12-04 01:01:17 +02:00
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
# If in test mode and this is a test messsage then delay so the calling process has time to read the message
|
|
|
|
if ($bTest && $strLevel eq TEST && $fTestDelay > 0)
|
|
|
|
{
|
|
|
|
usleep($fTestDelay * 1000000);
|
|
|
|
}
|
2014-02-14 01:11:53 +03:00
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
$rExtra->{bLogConsole} = true;
|
|
|
|
}
|
|
|
|
|
2017-09-01 01:15:44 +02:00
|
|
|
# Output to file if configured log level setting rank is greater than the display level rank or test flag is set.
|
|
|
|
if (!$rExtra->{bLogLogFile} && $iLogDisplayLevelRank <= $oLogLevelRank{$strLogLevelFile}{rank})
|
2014-02-14 01:11:53 +03:00
|
|
|
{
|
2017-01-27 16:42:30 +02:00
|
|
|
if (defined($hLogFile) || (defined($strLogLevelFile) && $strLogLevelFile ne OFF))
|
2014-09-30 22:51:08 +03:00
|
|
|
{
|
2017-01-27 16:42:30 +02:00
|
|
|
if (!$bSuppressLog)
|
2015-01-24 01:28:39 +02:00
|
|
|
{
|
2016-09-14 23:40:13 +02:00
|
|
|
if (defined($hLogFile))
|
|
|
|
{
|
2017-02-05 17:37:54 +02:00
|
|
|
logBanner();
|
2017-01-27 16:42:30 +02:00
|
|
|
syswrite($hLogFile, $strMessageFormat);
|
2016-09-14 23:40:13 +02:00
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
2017-01-27 16:42:30 +02:00
|
|
|
$strLogFileCache .= $strMessageFormat;
|
|
|
|
}
|
|
|
|
|
2017-09-01 01:15:44 +02:00
|
|
|
if ($strDisplayLevel eq ASSERT ||
|
|
|
|
($strDisplayLevel eq ERROR && ($strLogLevelFile eq DEBUG || $strLogLevelFile eq TRACE)))
|
2017-01-27 16:42:30 +02:00
|
|
|
{
|
|
|
|
my $strStackTrace = longmess() . "\n";
|
|
|
|
$strStackTrace =~ s/\n/\n /g;
|
|
|
|
|
|
|
|
if (defined($hLogFile))
|
|
|
|
{
|
|
|
|
syswrite($hLogFile, $strStackTrace);
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
$strLogFileCache .= $strStackTrace;
|
|
|
|
}
|
2016-09-14 23:40:13 +02:00
|
|
|
}
|
2015-01-24 01:28:39 +02:00
|
|
|
}
|
2014-09-30 22:51:08 +03:00
|
|
|
}
|
2016-12-04 01:01:17 +02:00
|
|
|
|
2017-01-27 16:42:30 +02:00
|
|
|
$rExtra->{bLogFile} = true;
|
|
|
|
}
|
2014-02-13 21:54:43 +03:00
|
|
|
}
|
2014-02-03 03:03:05 +03:00
|
|
|
|
2017-10-21 20:11:33 +02:00
|
|
|
# Return a typed exception if code is defined
|
2014-06-07 18:51:27 +03:00
|
|
|
if (defined($iCode))
|
|
|
|
{
|
2017-10-21 20:11:33 +02:00
|
|
|
$oErrorLast = new pgBackRest::Common::Exception($strLevel, $iCode, $strMessage, longmess(), $rExtra);
|
|
|
|
return $oErrorLast;
|
2014-06-07 18:51:27 +03:00
|
|
|
}
|
|
|
|
|
2017-10-21 20:11:33 +02:00
|
|
|
# Return the message so it can be used in a confess
|
2014-02-03 03:03:05 +03:00
|
|
|
return $strMessage;
|
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(log);
|
2015-04-24 02:52:41 +02:00
|
|
|
|
2017-10-21 20:11:33 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logErrorLast - get the last logged error
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logErrorLast
|
|
|
|
{
|
|
|
|
return $oErrorLast;
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logErrorLast);
|
|
|
|
|
2015-04-24 02:52:41 +02:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# testSet
|
|
|
|
#
|
|
|
|
# Set test parameters.
|
2015-04-24 02:52:41 +02:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
sub testSet
|
2015-04-24 02:52:41 +02:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
my $bTestParam = shift;
|
|
|
|
my $fTestDelayParam = shift;
|
2015-10-08 17:43:56 +02:00
|
|
|
my $oTestPointParam = shift;
|
2015-04-24 02:52:41 +02:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# Set defaults
|
|
|
|
$bTest = defined($bTestParam) ? $bTestParam : false;
|
|
|
|
$fTestDelay = defined($bTestParam) ? $fTestDelayParam : $fTestDelay;
|
2015-10-08 17:43:56 +02:00
|
|
|
$oTestPoint = $oTestPointParam;
|
2015-04-24 02:52:41 +02:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# Make sure that a delay is specified in test mode
|
|
|
|
if ($bTest && !defined($fTestDelay))
|
2015-04-24 02:52:41 +02:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
confess &log(ASSERT, 'iTestDelay must be provided when bTest is true');
|
2015-04-24 02:52:41 +02:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
# Test delay should be between 1 and 600 seconds
|
|
|
|
if (!($fTestDelay >= 0 && $fTestDelay <= 600))
|
2015-07-12 01:07:28 +02:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
confess &log(ERROR, 'test-delay must be between 1 and 600 seconds');
|
2015-07-12 01:07:28 +02:00
|
|
|
}
|
2015-04-24 02:52:41 +02:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(testSet);
|
2015-04-24 02:52:41 +02:00
|
|
|
|
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
# testCheck - Check for a test message
|
2015-04-24 02:52:41 +02:00
|
|
|
####################################################################################################################################
|
2015-08-29 20:20:46 +02:00
|
|
|
sub testCheck
|
2015-04-24 02:52:41 +02:00
|
|
|
{
|
2015-08-29 20:20:46 +02:00
|
|
|
my $strLog = shift;
|
|
|
|
my $strTest = shift;
|
2015-04-24 02:52:41 +02:00
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
return index($strLog, TEST_ENCLOSE . '-' . $strTest . '-' . TEST_ENCLOSE) != -1;
|
2015-04-24 02:52:41 +02:00
|
|
|
}
|
|
|
|
|
2015-08-29 20:20:46 +02:00
|
|
|
push @EXPORT, qw(testCheck);
|
|
|
|
|
2017-04-10 19:53:19 +02:00
|
|
|
####################################################################################################################################
|
|
|
|
# logLevel - get the current log levels
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logLevel
|
|
|
|
{
|
|
|
|
return ($strLogLevelFile, $strLogLevelConsole, $strLogLevelStdErr, $bLogTimestamp);
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logLevel);
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# logFileCacheClear - Clear the log file cache
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logFileCacheClear
|
|
|
|
{
|
|
|
|
undef($strLogFileCache);
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logFileCacheClear);
|
|
|
|
|
|
|
|
####################################################################################################################################
|
|
|
|
# logFileCache - Get the log file cache
|
|
|
|
####################################################################################################################################
|
|
|
|
sub logFileCache
|
|
|
|
{
|
|
|
|
return $strLogFileCache;
|
|
|
|
}
|
|
|
|
|
|
|
|
push @EXPORT, qw(logFileCache);
|
|
|
|
|
2014-06-04 18:58:30 +03:00
|
|
|
1;
|