feat: revamp logs

All connections and plugin executions emit two logs, an 'open' and
a 'close' log. We now add all the details of the connection to
the 'close' logs, those that were previously only available in the
corresponding 'open' log. This way, it is no longer required to
correlate both logs with their uniqid to have all the data:
the 'close' log should suffice. The 'open' log is still there if
for some reason the 'close' log can't be emitted (kill -9, system
crash, etc.), or if the 'open' and the 'close' log are several
hours, days or months appart.

An additional field "duration" has been added to the 'close' logs,
this represents the number of seconds (with millisecond precision)
the connection lasted.

Two new fields "globalsql" and "accountsql" have been added to the
'open'-type logs. These will contain either "ok" if we successfully
logged to the corresponding log database, "no" if it is disabled,
or "error $aDetailedMessage" if we got an error trying to insert
the row. The 'close'-type log also has the new "accountsql_close"
field, but misses the "globalsql_close" field as we never update
the global database on this event. On the 'close' log, we can also
have the value "missing", indicating that we couldn't update the
access log row in the database, as the corresponding 'open' log
couldn't insert it.

The "ttyrecsize" log field for the 'close'-type logs has been removed,
as it was never completely implemented, and contains bogus data if
ttyrec log rotation occurs. It has also been removed from the sqlite
log databases.

The 'open' and 'close' events are now pushed to our own log files,
in addition to syslog, if logging to those files is enabled (see
``enableGlobalAccesssLog`` and ``enableAccountAccessLog``), previously
the 'close' events were only pushed to syslog.

The /home/osh.log is no longer used for ``enableGlobalAccessLog``, the
global log is instead written to /home/logkeeper/global-log-YYYYMM.log.

The global sql file, enabled with ``enableGlobalSqlLog``, is now
split by year-month instead of by year, to
/home/logkeeper/global-log-YYYYMM.sqlite.
This commit is contained in:
Stéphane Lesimple 2020-12-15 15:39:20 +00:00
parent 9d1d613554
commit a479810d83
No known key found for this signature in database
GPG key ID: 4B4A3289E9D35658
9 changed files with 236 additions and 162 deletions

View file

@ -751,19 +751,6 @@ if [ "$nothing" = 0 ]; then
action_error "No group lastoshuser was found (!)"
fi
# log
action_doing "Create /home/osh.log"
if [ ! -e /home/osh.log ] ; then
touch /home/osh.log
chmod a+w /home/osh.log
if command -v chattr &>/dev/null; then
chattr +a /home/osh.log 2>/dev/null || true
fi
action_done
else
action_na
fi
action_doing "Create /var/log/bastion if needed"
if [ ! -d /var/log/bastion ] ; then
mkdir -p /var/log/bastion
@ -1056,19 +1043,15 @@ if [ "$nothing" = 0 ]; then
action_doing "Replacing legacy o+w by bastion-users/g+w"
at_least_one_changed=0
for file in $(test -f /home/osh.log && find /home/osh.log -perm -o+w) $(find /home/logkeeper/ -mindepth 1 -maxdepth 1 -type f -name "global-log-????.sqlite" -perm -o+w)
for file in $(test -f /home/osh.log && find /home/osh.log -perm -o+w) $(find /home/logkeeper/ -mindepth 1 -maxdepth 1 -type f -name "global-log-*" -perm -o+w)
do
if [ "$file" = /home/osh.log ]; then
if command -v chattr &>/dev/null; then
chattr -a /home/osh.log 2>/dev/null || true
fi
if echo "$file" | grep -Eq '\.log$' && command -v chattr &>/dev/null; then
chattr -a "$file" 2>/dev/null || true
fi
chown root:bastion-users "$file"
chmod 660 "$file"
if [ "$file" = /home/osh.log ]; then
if command -v chattr &>/dev/null; then
chattr +a /home/osh.log 2>/dev/null || true
fi
if echo "$file" | grep -Eq '\.log$' && command -v chattr &>/dev/null; then
chattr +a "$file" 2>/dev/null || true
fi
at_least_one_changed=1
done

View file

@ -416,10 +416,10 @@ OVH::Bastion::syslogFormatted(
severity => 'info',
type => 'account',
fields => [
['action', 'create'],
['account', $account],
['uid', $uid],
['public_key', @vettedKeys ? $vettedKeys[0] : undef],
['action', 'create'],
['account', $account],
['account_uid', $uid],
['public_key', @vettedKeys ? $vettedKeys[0] : undef],
['always_active', ($alwaysActive ? 'true' : 'false')],
['uid_auto', ($uidAuto ? 'true' : 'false')],
['osh_only', ($oshOnly ? 'true' : 'false')],

View file

@ -6,7 +6,7 @@ use common::sense;
# that is launching us. we don't use GetOpts or such, as this is not
# user-modifiable anyway. We're mainly passing parameters we will need
# in this short script. some of them can sometimes be undef. this is normal.
my ($ip, $sshClientHasOptionE, $userPasswordClue, $saveFile, $insert_id, $db_name, $uniq_id, @command) = @ARGV;
my ($ip, $sshClientHasOptionE, $userPasswordClue, $saveFile, $insert_id, $db_name, $uniq_id, $self, @command) = @ARGV;
# on signal (HUP happens a lot), still try to log in db
sub exit_sig {
@ -21,11 +21,11 @@ sub exit_sig {
# and log
OVH::Bastion::log_access_update(
insert_id => $insert_id,
db_name => $db_name,
uniq_id => $uniq_id,
returnvalue => -9999,
comment => 'signal_' . $sig
account => $self,
insert_id => $insert_id,
db_name => $db_name,
uniq_id => $uniq_id,
signal => $sig,
);
}
@ -205,6 +205,7 @@ else {
# update our sql line if we successfully inserted it back in osh.pl
OVH::Bastion::log_access_update(
account => $self,
insert_id => $insert_id,
db_name => $db_name,
uniq_id => $uniq_id,
@ -212,7 +213,6 @@ OVH::Bastion::log_access_update(
comment => @comments ? join(' ', @comments) : undef,
timestampend => $timestamp,
timestampendusec => $timestampusec,
ttyrecsize => (stat($saveFile))[7], # FIXME we miss ttyrec rotations, need to fix a bug in ovh-ttyrec before ...
);
if ($sysret == -1) {

View file

@ -488,6 +488,7 @@ if ($interactive and not $ENV{'OSH_NO_INTERACTIVE'}) {
if (defined $log_insert_id and defined $log_db_name) {
$logret = OVH::Bastion::log_access_update(
account => $self,
insert_id => $log_insert_id,
db_name => $log_db_name,
uniq_id => $log_uniq_id,
@ -923,10 +924,11 @@ if ($osh_command) {
if (defined $log_insert_id and defined $log_db_name) {
$logret = OVH::Bastion::log_access_update(
account => $self,
insert_id => $log_insert_id,
db_name => $log_db_name,
uniq_id => $log_uniq_id,
returnvalue => $fnret->value ? $fnret->value->{'sysret'} : undef,
returnvalue => $fnret->value ? $fnret->value->{'sysret_raw'} : undef,
plugin_stdout => $fnret->value ? $fnret->value->{'stdout'} : undef,
plugin_stderr => $fnret->value ? $fnret->value->{'stderr'} : undef
);
@ -1316,8 +1318,12 @@ if (!$quiet) {
push @toExecute, $OVH::Bastion::BASEPATH . '/bin/shell/connect.pl';
exec(
@toExecute, $ip, $config->{'sshClientHasOptionE'}, $userPasswordClue, $saveFile,
$logret->value->{'insert_id'}, $logret->value->{'db_name'}, $logret->value->{'uniq_id'}, @ttyrec
@toExecute, $ip, $config->{'sshClientHasOptionE'},
$userPasswordClue, $saveFile,
$logret->value->{'insert_id'},
$logret->value->{'db_name'},
$logret->value->{'uniq_id'},
$self, @ttyrec
) or exit(OVH::Bastion::EXIT_EXEC_FAILED);
exit OVH::Bastion::EXIT_OK;
@ -1333,11 +1339,11 @@ sub exit_sig {
my ($sig) = @_;
if (defined $log_insert_id and defined $log_db_name) {
OVH::Bastion::log_access_update(
insert_id => $log_insert_id,
db_name => $log_db_name,
uniq_id => $log_uniq_id,
returnvalue => -9999,
comment => 'signal_' . $sig
account => $self,
insert_id => $log_insert_id,
db_name => $log_db_name,
uniq_id => $log_uniq_id,
signal => $sig,
);
}
exit OVH::Bastion::EXIT_OK;

View file

@ -418,7 +418,7 @@ enableSyslog
:Default: ``true``
If set to ``false``, syslog will be disabled. If set to ``true``, we'll send logs through syslog (don't forget to setup your syslog daemon!).
If enabled, we'll send logs through syslog, don't forget to setup your syslog daemon!. You can also adjust ``syslogFacility`` and ``syslogDescription`` below, to match your syslog configuration. Note that the provided ``syslog-ng`` templates work with the default values left as-is.
.. _bastion_conf_syslogFacility:
@ -451,7 +451,7 @@ enableGlobalAccessLog
:Default: ``true``
If set to ``true``, all accesses will still be logged in ``/home/osh.log``. This file is never rotated and is world writable, this is discouraged: please use syslog insteead.
If enabled, all *open* and *close* logs will be written to ``/home/logkeeper/global-log-YYYYMM.log``. Those are also logged through syslog if *enableSyslog* is set.
.. _bastion_conf_enableAccountAccessLog:
@ -462,7 +462,7 @@ enableAccountAccessLog
:Default: ``true``
If set to ``true``, all accesses will still be logged in the user's home ``/home/USER/USER-log-YYYYMM.log``. If set to ``false``, we won't log there.
If enabled, all *open* and *close* logs will be written to the corresponding user's home in ``/home/USER/USER-log-YYYYMM.log``. Those are also logged through syslog if *enableSyslog* is set.
.. _bastion_conf_enableGlobalSqlLog:
@ -473,7 +473,7 @@ enableGlobalSqlLog
:Default: ``true``
If set to ``true``, all accesses will be logged (in a short SQL format) in ``/home/logkeeper/*.sqlite``. If set to ``false``, we won't log there.
If enabled, all access logs (corresponding to the *open* and *close* events) will be written in a short SQL format, as one row per access, to ``/home/logkeeper/global-log-YYYYMM.sqlite``.
.. _bastion_conf_enableAccountSqlLog:
@ -484,7 +484,7 @@ enableAccountSqlLog
:Default: ``true``
If set to ``true``, all accesses will be logged (in a detailed SQL format) in the user's home ``/home/USER/USER-log-YYYYMM.sqlite``. Otherwise, we won't log there.
If enabled, all access logs (corresponding to the *open* and *close* events) will be written in a detailed SQL format, as one row per access, in the corresponding user's home to ``/home/USER/USER-log-YYYYMM.sqlite``. If you want to use ``selfListSessions`` and/or ``selfPlaySession``, this is required.
.. _bastion_conf_ttyrecFilenameFormat:

View file

@ -163,7 +163,7 @@
# >> Options to customize how logs should be produced.
#
# enableSyslog (boolean)
# DESC: If set to ``false``, syslog will be disabled. If set to ``true``, we'll send logs through syslog (don't forget to setup your syslog daemon!).
# DESC: If enabled, we'll send logs through syslog, don't forget to setup your syslog daemon!. You can also adjust ``syslogFacility`` and ``syslogDescription`` below, to match your syslog configuration. Note that the provided ``syslog-ng`` templates work with the default values left as-is.
# DEFAULT: true
"enableSyslog": true,
#
@ -178,22 +178,22 @@
"syslogDescription": "bastion",
#
# enableGlobalAccessLog (boolean)
# DESC: If set to ``true``, all accesses will still be logged in ``/home/osh.log``. This file is never rotated and is world writable, this is discouraged: please use syslog insteead.
# DESC: If enabled, all *open* and *close* logs will be written to ``/home/logkeeper/global-log-YYYYMM.log``. Those are also logged through syslog if *enableSyslog* is set.
# DEFAULT: true
"enableGlobalAccessLog": true,
#
# enableAccountAccessLog (boolean)
# DESC: If set to ``true``, all accesses will still be logged in the user's home ``/home/USER/USER-log-YYYYMM.log``. If set to ``false``, we won't log there.
# DESC: If enabled, all *open* and *close* logs will be written to the corresponding user's home in ``/home/USER/USER-log-YYYYMM.log``. Those are also logged through syslog if *enableSyslog* is set.
# DEFAULT: true
"enableAccountAccessLog": true,
#
# enableGlobalSqlLog (boolean)
# DESC: If set to ``true``, all accesses will be logged (in a short SQL format) in ``/home/logkeeper/*.sqlite``. If set to ``false``, we won't log there.
# DESC: If enabled, all access logs (corresponding to the *open* and *close* events) will be written in a short SQL format, as one row per access, to ``/home/logkeeper/global-log-YYYYMM.sqlite``.
# DEFAULT: true
"enableGlobalSqlLog": true,
#
# enableAccountSqlLog (boolean)
# DESC: If set to ``true``, all accesses will be logged (in a detailed SQL format) in the user's home ``/home/USER/USER-log-YYYYMM.sqlite``. Otherwise, we won't log there.
# DESC: If enabled, all access logs (corresponding to the *open* and *close* events) will be written in a detailed SQL format, as one row per access, in the corresponding user's home to ``/home/USER/USER-log-YYYYMM.sqlite``. If you want to use ``selfListSessions`` and/or ``selfPlaySession``, this is required.
# DEFAULT: true
"enableAccountSqlLog": true,
#

View file

@ -33,7 +33,7 @@ BEGIN {
OVH::Bastion::syslogFormatted(
criticity => $criticity,
type => $type,
fields => [['sudouser', $ENV{'SUDO_USER'}], ['version', $OVH::Bastion::VERSION], ['msg', $msg], ['program', $0], ['cmdline', $_SAVED_ARGV], ['trace', Carp::longmess()]]
fields => [['msg', $msg], ['program', $0], ['cmdline', $_SAVED_ARGV], ['trace', Carp::longmess()]]
);
return 1;
}
@ -129,7 +129,7 @@ my %_autoload_files = (
qw{ is_user_in_group is_group_existing get_acl_from_file get_account_acl is_valid_uid get_next_available_uid is_bastion_account_valid_and_existing is_account_valid is_account_existing access_modify is_valid_group is_valid_group_and_existing add_user_to_group get_group_servers_list get_group_list get_account_list is_admin is_super_owner is_group_aclkeeper is_group_gatekeeper is_group_owner is_group_guest is_group_member is_auditor get_remote_accounts_from_realm is_valid_ttl get_realm_list }
],
configuration => [qw{ load_configuration_file main_configuration_directory load_configuration config account_config plugin_config group_config json_load }],
execute => [qw{ execute result_from_helper helper_decapsulate helper }],
execute => [qw{ sysret2human execute result_from_helper helper_decapsulate helper }],
interactive => [qw{ interactive }],
log => [qw{ syslog syslog_close syslogFormatted warn_syslog log_access_insert log_access_update log_access_get }],
os => [

View file

@ -15,7 +15,7 @@ use Config;
my %signum2string;
@signum2string{split ' ', $Config{sig_num}} = map { "SIG$_" } split ' ', $Config{sig_name};
sub _sysret2human {
sub sysret2human {
my $sysret = shift;
if ($sysret == -1) {
return R('OK', msg => "error: failed to execute ($!)");
@ -28,13 +28,13 @@ sub _sysret2human {
value => {
coredump => $coredump ? \1 : \0,
signal => $signum2string{$signal} || $signal,
status => 0,
status => undef,
},
msg => sprintf("signal %d (%s)%s", $signal, $signum2string{$signal}, $coredump ? ' and coredump' : '')
);
}
else {
return R('OK', value => {coredump => \0, signal => 0, status => $sysret >> 8}, msg => sprintf("status %d", $sysret >> 8));
return R('OK', value => {coredump => \0, signal => undef, status => $sysret >> 8}, msg => sprintf("status %d", $sysret >> 8));
}
}
@ -83,7 +83,7 @@ sub execute {
if ($system) {
my $child_exit_status = system(@$cmd);
$fnret = _sysret2human($child_exit_status);
$fnret = sysret2human($child_exit_status);
return R(
$child_exit_status == 0 ? 'OK' : ($must_succeed ? 'ERR_NON_ZERO_EXIT' : 'OK_NON_ZERO_EXIT'),
value => {
@ -92,7 +92,7 @@ sub execute {
coredump => $fnret->value->{'coredump'},
signal => $fnret->value->{'signal'},
},
msg => "Command exited with " . _sysret2human($child_exit_status)->msg,
msg => "Command exited with " . sysret2human($child_exit_status)->msg,
);
}
@ -311,20 +311,21 @@ sub execute {
waitpid($pid, 0);
my $child_exit_status = $?;
$fnret = _sysret2human($child_exit_status);
$fnret = sysret2human($child_exit_status);
osh_debug("cmd returned with " . $fnret->msg);
return R(
$fnret->value->{'status'} == 0 ? 'OK' : ($must_succeed ? 'ERR_NON_ZERO_EXIT' : 'OK_NON_ZERO_EXIT'),
value => {
sysret => $child_exit_status >> 8,
stdout => $output{stdout},
stderr => $output{stderr},
bytesnb => \%bytesnb,
status => $fnret->value->{'status'},
coredump => $fnret->value->{'coredump'},
signal => $fnret->value->{'signal'},
sysret => $child_exit_status >> 8,
sysret_raw => $child_exit_status,
stdout => $output{stdout},
stderr => $output{stderr},
bytesnb => \%bytesnb,
status => $fnret->value->{'status'},
coredump => $fnret->value->{'coredump'},
signal => $fnret->value->{'signal'},
},
msg => "Command exited with " . _sysret2human($child_exit_status)->msg,
msg => "Command exited with " . sysret2human($child_exit_status)->msg,
);
}

View file

@ -6,6 +6,7 @@ use common::sense;
use DBD::SQLite;
use Time::HiRes;
use Sys::Syslog qw();
use JSON;
my $_syslog_inited = 0; # lazy init
@ -46,25 +47,29 @@ END {
}
sub syslogFormatted {
# do NOT use warn_syslog in this func, or we would loop. warn() is fine.
my %params = @_;
my $criticity = $params{'criticity'} || 'info';
my $type = $params{'type'} || 'unknown';
my $fields = $params{'fields'};
my $fieldsref = $params{'fields'};
if (ref $fields ne 'ARRAY') {
if (ref $fieldsref ne 'ARRAY') {
my $error = "bad call to syslogFormatted, invalid fields parameter";
warn($error); # this will in turn log into syslog with the trace() thanks to the SIG{'WARN'} handler
return R('INTERNAL_ERROR', msg => $error);
}
unshift @$fields, ['gid', ((split(/ /, $)))[0])];
unshift @$fields, ['uid', $>];
unshift @$fields, ['sudo_user', $ENV{'SUDO_USER'}];
unshift @$fields, ['sysuser', OVH::Bastion::get_user_from_env()->value];
unshift @$fields, ['ppid', getppid()];
unshift @$fields, ['pid', $$];
unshift @$fields, ['version', $OVH::Bastion::VERSION];
unshift @$fields, ['uniqid', ($ENV{'UNIQID'} || '-')];
my @fields = @$fieldsref;
unshift @fields, ['gid', ((split(/ /, $)))[0])];
unshift @fields, ['uid', $>];
unshift @fields, ['sudo_user', $ENV{'SUDO_USER'}];
unshift @fields, ['sysuser', OVH::Bastion::get_user_from_env()->value];
unshift @fields, ['ppid', getppid()];
unshift @fields, ['pid', $$];
unshift @fields, ['version', $OVH::Bastion::VERSION];
unshift @fields, ['uniqid', ($ENV{'UNIQID'} || '-')];
my @msg = ($type);
if (($type eq 'die' || $type eq 'warn') && $criticity eq 'info') {
@ -73,9 +78,10 @@ sub syslogFormatted {
@msg = ("$type-$criticity");
}
foreach my $item (@$fields) {
my %dedupe;
foreach my $item (@fields) {
# each @$fields item is a 2-dimensional array for key => value
# each $item item is a 2-dimensional array for key => value
if (ref $item ne 'ARRAY') {
my $error = "bad call to syslogFormatted, invalid item in fields (ref " . (ref $item) . ")";
warn($error);
@ -83,6 +89,12 @@ sub syslogFormatted {
}
my ($key, $value) = @$item;
# warn if we have the same key more than once
if (exists $dedupe{$key}) {
warn("syslogFormatted(): got multiple '$key' keys");
}
$dedupe{$key} = $value;
# remove any \n in the value
$value =~ s/\n/ /g;
@ -228,7 +240,6 @@ sub _sql_log_insert_file {
my $plugin = $params{'plugin'};
my $params = $params{'params'};
my $comment = $params{'comment'};
my $ttyrecfile = $params{'ttyrecfile'};
my $timestamp = $params{'timestamp'};
my $timestampusec = $params{'timestampusec'};
my $uniqid = $params{'uniqid'};
@ -283,11 +294,11 @@ sub _sql_log_insert_file {
if ($sqltype eq 'local') {
$prepare =
"INSERT INTO connections"
. "(uniqid,timestamp,timestampusec,account,cmdtype,allowed,hostfrom,ipfrom,portfrom,bastionip,bastionport,hostto,ipto,portto,user,plugin,params,comment,ttyrecfile)"
. "VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)";
. "(uniqid,timestamp,timestampusec,account,cmdtype,allowed,hostfrom,ipfrom,portfrom,bastionip,bastionport,hostto,ipto,portto,user,plugin,params,comment)"
. "VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)";
@execute = (
$uniqid, $timestamp, $timestampusec, $account, $cmdtype, $allowed, $hostfrom, $ipfrom, $portfrom, $bastionip,
$bastionport, $hostto, $ipto, $portto, $user, $plugin, $params, $comment, $ttyrecfile
$uniqid, $timestamp, $timestampusec, $account, $cmdtype, $allowed, $hostfrom, $ipfrom, $portfrom,
$bastionip, $bastionport, $hostto, $ipto, $portto, $user, $plugin, $params, $comment
);
}
elsif ($sqltype eq 'global') {
@ -331,17 +342,20 @@ sub log_access_insert {
my $custom = $params{'custom'}; # only used for proxyhttp, not pushed to sql
my $fnret;
if (not defined $account) {
return R('ERR_MISSING_PARAMETER', msg => "Missing parameter 'account'");
# if we get a valid account, we'll try to log to its files, if enabled.
# if not, or if its invalid, still try to log what we can (hence don't return here)
my ($remoteaccount, $sysaccount);
if (defined $account) {
if ($fnret = OVH::Bastion::is_bastion_account_valid_and_existing(account => $account)) {
$account = $fnret->value->{'account'};
$sysaccount = $fnret->value->{'sysaccount'};
$remoteaccount = $fnret->value->{'remoteaccount'};
}
else {
undef $account;
}
}
$fnret = OVH::Bastion::is_bastion_account_valid_and_existing(account => $account);
$fnret or return $fnret;
$account = $fnret->value->{'account'};
my $sysaccount = $fnret->value->{'sysaccount'};
my $remoteaccount = $fnret->value->{'remoteaccount'};
$loghome ||= $sysaccount;
$params{'account'} = $account;
@ -365,23 +379,36 @@ sub log_access_insert {
$params{'timestamp'} = $timestamp;
$params{'timestampusec'} = $timestampusec;
my @localtime = localtime(time());
my $sqlfile_global = sprintf("/home/logkeeper/global-log-%04d.sqlite", $localtime[5] + 1900);
my $sqlfile_account =
sprintf("/home/%s/%s-log-%04d%02d.sqlite", $params{'loghome'}, $remoteaccount || $loghome, $localtime[5] + 1900, $localtime[4] + 1);
# first, log in account sql file
# 1/3) log into sql databases if enabled
my @localtime = localtime(time());
my ($insert_id, $db_name);
# first, log in account db
my $accountsql = 'no';
if (OVH::Bastion::config('enableAccountSqlLog')->value()) {
$params{'file'} = $sqlfile_account;
$params{'sqltype'} = 'local';
$fnret = _sql_log_insert_file(%params);
$fnret = _sql_log_insert_file(
%params,
sqltype => "local",
file => sprintf("/home/%s/%s-log-%04d%02d.sqlite", $loghome, $remoteaccount || $loghome, $localtime[5] + 1900, $localtime[4] + 1)
);
if ($fnret) {
($insert_id, $db_name) = ($fnret->value->{'id'}, $params{'file'});
$accountsql = 'ok';
}
else {
$accountsql = 'error ' . $fnret->msg;
}
}
# then, syslog, we'll also say if the sqlinsert failed
# then global db
my $globalsql = 'no';
if (OVH::Bastion::config('enableGlobalSqlLog')->value()) {
$fnret = _sql_log_insert_file(%params, sqltype => "global", file => sprintf("/home/logkeeper/global-log-%04d%02d.sqlite", $localtime[5] + 1900, $localtime[4] + 1));
$globalsql = $fnret ? 'ok' : 'error ' . $fnret->msg;
}
# 2/3) push to syslog, we'll also say if any sqlinsert failed through globalsql/accountsql
# even if syslog is disabled, syslogFormatted() will return a oneline $msg that we'll use afterwards
my @fields = (
['account', $account],
['cmdtype', $params{'cmdtype'}],
@ -397,43 +424,36 @@ sub log_access_insert {
['port_to', $params{'portto'}],
['host_to', $params{'hostto'}],
['plugin', $params{'plugin'}],
['globalsql', $globalsql],
['accountsql', $accountsql],
['comment', $params{'comment'}],
['sqlfile', ($fnret ? '' : 'ERR:') . $params{'file'}],
['params', $params{'params'}],
['params', $params{'params'}],
);
if (ref $custom eq 'ARRAY') {
foreach my $item (@$custom) {
push @fields, $item if (ref $item eq 'ARRAY' && @$item == 2);
}
}
$fnret = OVH::Bastion::syslogFormatted(
$fnret = syslogFormatted(
criticity => 'info',
type => 'open',
fields => \@fields,
);
my $msg = '(empty)';
$msg = $fnret->value if $fnret;
# then, log in oldschool files
if (OVH::Bastion::config('enableAccountAccessLog')->value()) {
if (open(my $log_acc, ">>", sprintf("/home/%s/%s-log-%04d%02d.log", $params{'loghome'}, $remoteaccount || $loghome, $localtime[5] + 1900, $localtime[4] + 1))) {
print $log_acc localtime() . " $msg\n";
close($log_acc);
}
}
if (OVH::Bastion::config('enableGlobalAccessLog')->value()) {
if (open(my $log_gen, ">>", "/home/osh.log")) {
print $log_gen localtime() . " $msg\n";
close($log_gen);
}
}
# if syslogFormatted failed, we'll log its error message (->msg) instead of the message it couldn't assemble (->value)
my $msg = $fnret ? $fnret->value : $fnret->msg;
# then global sql
if (OVH::Bastion::config('enableGlobalSqlLog')->value()) {
$params{'file'} = $sqlfile_global;
$params{'sqltype'} = 'global';
$fnret = _sql_log_insert_file(%params);
}
# 3/3) push to our own local / global text logs, if enabled, using the $msg returned by syslogFormatted
_write_log(account => $account, sysaccount => $loghome, remoteaccount => $remoteaccount, msg => $msg);
# save this for log_access_update()
my $cache = {
fields => \@fields,
timestamp => $params{'timestamp'},
timestampusec => $params{'timestampusec'},
};
$ENV{'LOG_CACHE_' . $params{'uniqid'}} = encode_json($cache);
return R('OK', value => {insert_id => $insert_id, db_name => $db_name, uniq_id => $params{'uniqid'}});
}
@ -446,7 +466,6 @@ sub _sql_log_update_file {
my $comment = $params{'comment'};
my $timestampend = $params{'timestampend'};
my $timestampendusec = $params{'timestampendusec'};
my $ttyrecsize = $params{'ttyrecsize'};
my $plugin_stdout = $params{'plugin_stdout'};
my $plugin_stderr = $params{'plugin_stderr'};
@ -486,10 +505,6 @@ sub _sql_log_update_file {
$prepare .= ", comment=?";
push @execute, $comment;
}
if (defined $ttyrecsize) {
$prepare .= ", ttyrecsize=?";
push @execute, $ttyrecsize;
}
$prepare .= " WHERE id=? AND timestampend IS NULL";
push @execute, $id;
@ -584,40 +599,120 @@ EOS
return R('OK');
}
# called by log_access_insert and log_access_update
# don't re-check the validity of our params, this has been done by our callers
sub _write_log {
my %params = @_;
my @localtime = localtime(time());
my @date = ($localtime[5] + 1900, $localtime[4] + 1);
if (OVH::Bastion::config('enableAccountAccessLog')->value() && $params{'sysaccount'}) {
if (open(my $log_acc, ">>", sprintf("/home/%s/%s-log-%04d%02d.log", $params{'sysaccount'}, $params{'remoteaccount'} || $params{'sysaccount'}, @date))) {
print $log_acc localtime() . " " . $params{'msg'} . "\n";
close($log_acc);
}
}
if (OVH::Bastion::config('enableGlobalAccessLog')->value()) {
if (open(my $log_gen, ">>", sprintf("/home/logkeeper/global-log-%04d%02d.log", @date))) {
print $log_gen localtime() . " " . $params{'msg'} . "\n";
close($log_gen);
}
}
return;
}
sub log_access_update {
my %params = @_;
my $account = $params{'account'};
my $insert_id = $params{'insert_id'};
my $db_name = $params{'db_name'};
my $uniq_id = $params{'uniq_id'};
my $fnret;
# if we get a valid account, we'll try to log to its files, if enabled.
# if not, or if its invalid, still try to log what we can (hence don't return here)
my ($remoteaccount, $sysaccount);
if (defined $account) {
if ($fnret = OVH::Bastion::is_bastion_account_valid_and_existing(account => $account)) {
$account = $fnret->value->{'account'};
$sysaccount = $fnret->value->{'sysaccount'};
$remoteaccount = $fnret->value->{'remoteaccount'};
}
else {
undef $account;
}
}
if (not defined $params{'timestampend'} or not defined $params{'timestampendusec'}) {
($params{'timestampend'}, $params{'timestampendusec'}) = Time::HiRes::gettimeofday();
}
# in any case, send a syslog even if we miss insert_id or db_name
OVH::Bastion::syslogFormatted(
# retrieve info from the corresponding "open" log so that we can include it to our log
my @comments = $params{'comment'} ? split(" ", $params{'comment'}) : ();
my @fields;
my $duration = -1;
if (exists $ENV{'LOG_CACHE_' . $params{'uniq_id'}}) {
my $cache;
eval { $cache = decode_json(delete $ENV{'LOG_CACHE_' . $params{'uniq_id'}}); };
if ($cache) {
@fields = @{$cache->{'fields'}};
$duration = ($params{'timestampend'} + $params{'timestampendusec'} / 1_000_000) - ($cache->{'timestamp'} + $cache->{'timestampusec'} / 1_000_000);
}
}
if (!@fields) {
push @comments, "missing_open_log_info";
}
my $signal = '';
my $status = '';
if (defined $params{'returnvalue'}) {
$fnret = OVH::Bastion::sysret2human($params{'returnvalue'});
if ($fnret && $fnret->value) {
$signal = $fnret->value->{'signal'};
$status = $fnret->value->{'status'};
}
}
else {
# sql logs expect a returnvalue, so set one if we don't have any
$params{'returnvalue'} = -1;
}
# if an explicit signal value has been passed, use it
if ($params{'signal'}) {
$signal = delete $params{'signal'};
}
push @fields, ['sysret', $status], ['signal', $signal], ['comment_close', join(" ", @comments)], ['duration', sprintf("%.3f", $duration)];
# 1/3) update the account sql db if enabled. note that the global sql db is NOT updated, as
# it contains less details that the account databases and doesn't have any field that requires
# to wait the end of a connection to be filled.
my $accountsql = 'missing';
if ($insert_id && $db_name) {
if (OVH::Bastion::config('enableAccountSqlLog')->value()) {
$fnret = _sql_log_update_file(%params, file => $db_name, id => $insert_id);
$accountsql = $fnret ? 'ok' : 'error ' . $fnret->msg;
}
else {
$accountsql = 'no';
}
}
# 2/3) push to syslog, we'll also say if the sql update failed through accountsql
# even if syslog is disabled, syslogFormatted() will return a oneline $msg that we'll use afterwards
push @fields, [accountsql_close => $accountsql];
$fnret = syslogFormatted(
criticity => 'info',
type => 'close',
fields => [
# TODO: in addition to the specific "on-close" fields, we should re-log here everything
# that was logged in the log_access_insert call for easier SIEM analytics
['sysret', $params{'returnvalue'}],
['ttyrec_size', $params{'ttyrecsize'}],
['comment_close', $params{'comment'}],
]
fields => \@fields,
);
if (not defined $insert_id or not defined $db_name) {
return R('ERR_MISSING_PARAMETER', msg => "Missing required 'insert_id' or 'db_name'");
}
# if syslogFormatted failed, we'll log its error message (->msg) instead of the message it couldn't assemble (->value)
my $msg = $fnret ? $fnret->value : $fnret->msg;
$params{'file'} = $db_name;
$params{'id'} = $insert_id;
# 3/3) push to our own local / global text logs, if enabled, using the $msg returned by syslogFormatted
_write_log(account => $account, sysaccount => $sysaccount, remoteaccount => $remoteaccount, msg => $msg);
if (OVH::Bastion::config('enableAccountSqlLog')->value()) {
return _sql_log_update_file(%params);
}
return R('OK');
}
@ -641,7 +736,7 @@ sub log_access_get {
my @localtime = localtime(time());
# first, check in account sql file
# check in account sql file
if (OVH::Bastion::config('enableAccountSqlLog')->value()) {
$params{'file'} = sprintf("/home/%s/%s-log-%04d%02d.sqlite", $params{'account'}, $params{'account'}, $localtime[5] + 1900, $localtime[4] + 1);
$params{'sqltype'} = 'local';
@ -649,17 +744,6 @@ sub log_access_get {
return $fnret;
}
# second, check in global sql file
=cut not now, too slow and table columns differ
if (OVH::Bastion::config('enableGlobalSqlLog')->value()) {
$params{'file'} = sprintf("/home/logkeeper/global-log-%04d.sqlite", $localtime[5] + 1900);
$params{'sqltype'} = 'global';
$fnret = _sql_log_fetch_from_file(%params);
return $fnret;
}
=cut
return R('ERR_DISABLED', msg => "This feature is not available");
}