The Bastion comes with a lot of traceability features, you have to ensure that you've done your configuration correctly so that those logs are kept in a safe place when you need them. It is warmly advised to enable at least the syslog option, and push your logs to a remote syslog server.
The Bastion has several configurable ways of logging events, but before detailing those, let's see the different message types that can be logged. The Bastion currently has 12 different message types, listed below:
First, let's list the fields that are common to all the message types:
This is the unique connection ID, you can find all the logs relevant to the same connection by filtering on the
uniqid. This ID is also, by default, part of the filename given to the
ttyrecfiles, for easier correlation. The same ID is also used in the sqlite logs, if you enabled those. In some rare cases, the value can be "-", for example if a satellite script has something to log, not linked to an actual connection or session.
This indicates the version of The Bastion software that is writing the log
- pid, ppid
This is the system PID (resp. system parent PID) of the process writing the log, for easier correlation with system audit logs if you have them
This is the system user under which the process writing the log is currently running on, can be useful to detect abnormalities
When the value is present, it contains the system user name that has launched the
sudocommand the code is currently running under (this will be the case if a so-called "bastion helper" is pushing a log, for example). However this field will often have an empty value, it means that the code that is writing the log is not running under
- uid, gid
This is the system user ID aka UID (resp. group ID aka GID) under which the process writing the log is currently running
This is the name of the bastion account that launched the command that produced the log
The other fields depend on the message type, as detailed in the next sections.
This log is produced when a user established a session with the bastion.
Dec 28 11:12:26 myhostname bastion: open uniqid="e9e4baf6873b" version="3.01.03" pid="18721" ppid="18720" sysuser="gthreepw" sudo_user="" uid="99998" gid="99998" account="gthreepw" cmdtype="ssh" allowed="true" ip_from="172.17.0.1" port_from="39696" host_from="172.17.0.1" ip_bastion="172.17.0.2" port_bastion="22" host_bastion="myhostname.example.org" user="foo" ip_to="172.17.0.123" port_to="22" host_to="srv123.example.org" plugin="" globalsql="ok" accountsql="ok" comment="" params="ttyrec -f /home/gthreepw/ttyrec/172.17.0.123/2020-12-28.11-12-26.074894.e9e4baf6873b.gthreepw.foo.172.17.0.123.22.ttyrec -F /home/gthreepw/ttyrec/172.17.0.123/%Y--%d.%H-%M-%S.#usec#.e9e4baf6873b.gthreepw.foo.172.17.0.123.22.ttyrec -- /usr/bin/ssh 172.17.0.123 -l foo -p 22 -i /home/gthreepw/.ssh/id_rsa4096_private.1594384739 -i /home/keykeeper/keyagroup/id_ed25519_agroup.1607524914 -o PreferredAuthentications=publickey"
Indicates which category of command has been requested by the user:
ssh: the user is trying to establish an SSH egress connection to a remote server
telnet: the user is trying to establish a telnet egress connection to a remote server
abort: the action requested by the user has been aborted early, possibly because of permission issues or impossibility to understand the request, more information is available in the bastion_comment field
osh: the user is trying to execute a bastion plugin with the
interactive: the user just entered interactive mode. Note that all the commands launched through the interactive mode will still have their own log.
sshas: an administrator is currently establishing a connection on behalf of another user. This connection will also have its own log.
proxyhttp_daemon: the HTTPS proxy daemon received a request
proxyhttp_worker: the HTTPS proxy worker specifically spawned for the user by the daemon is handling the request
Indicates whether the requested action was allowed or not by the bastion, after executing the authorization phase. Will be either "true" or "false".
- ip_from, port_from, host_from
These are the IP and source port as seen by the bastion, from which the ingress connection originates. If the bastion can resolve the reverse of the IP to a hostname, it'll be indicated in host_from, otherwise the IP will be repeated there.
- ip_bastion, port_bastion, host_bastion
These are the IP and port of the bastion to which the ingress connection terminates. If your bastion has several IPs and/or interfaces, this can be useful. If the bastion can resolve the reverse of the IP to a hostname, it'll be indicated in host_bastion, otherwise the IP will be repeated there.
- ip_to, port_to, host_to
These are the IP and destination port to which the bastion will connect on the egress side, on behalf of the requesting user. If the bastion can resolve the reverse of the IP to a hostname, it'll be indicated in host_to, otherwise the IP will be repeated there.
osh, the name of the command (or plugin) will appear in this field. Otherwise it'll be blank.
This field will contain either:
ok: when enableAccountSqlLog is enabled, and we successfully inserted a new row for the log
no: when enableAccountSqlLog is disabled
error: when we couldn't insert a new row, error followed by a detailed error message, for example "error SQL error [global] err 8 while doing [inserting data (execute)]: attempt to write a readonly database".
This field can contain the same values than accountsql above, but for
Some more information about the current event, depending on the
This is the fully expanded command line that will be launched under the currently running user rights, to establish the egress connection, if applicable.
This log is produced when a user terminates a currently running session with The Bastion.
It is always matched (through the
uniqid) to another log with the
open message type.
Dec 28 11:12:26 myhostname bastion: open uniqid="e9e4baf6873b" version="3.01.03" pid="18721" ppid="18720" sysuser="gthreepw" sudo_user="" uid="99998" gid="99998" account="gthreepw" cmdtype="ssh" allowed="true" ip_from="172.17.0.1" port_from="39696" host_from="172.17.0.1" ip_bastion="172.17.0.2" port_bastion="22" host_bastion="myhostname.example.org" user="foo" ip_to="172.17.0.123" port_to="22" host_to="srv123.example.org" plugin="" globalsql="ok" accountsql="ok" comment="" params="ttyrec -f /home/gthreepw/ttyrec/172.17.0.123/2020-12-28.11-12-26.074894.e9e4baf6873b.gthreepw.foo.172.17.0.123.22.ttyrec -F /home/gthreepw/ttyrec/172.17.0.123/%Y--%d.%H-%M-%S.#usec#.e9e4baf6873b.gthreepw.foo.172.17.0.123.22.ttyrec -- /usr/bin/ssh 172.17.0.123 -l foo -p 22 -i /home/gthreepw/.ssh/id_rsa4096_private.1594384739 -i /home/keykeeper/keyagroup/id_ed25519_agroup.1607524914 -o PreferredAuthentications=publickey" sysret="0" signal="" comment_close="hostkey_changed passauth_disabled" duration="43.692"
All the fields from the corresponding
open log are repeated in this log line, in addition to the following fields:
Return code of the launched system command (that established the egress connection) or the plugin (if an
--oshcommand was passed). If we don't have a return code, for example because we were interrupted by a signal, the value will be empty.
Name of the UNIX signal that terminated the command, if any. For example "HUP" or "SEGV". If we got no signal, the value will be empty.
A space-separated list of messages giving some hints gathered at the end of a session. For example hostkey_changed passauth_disabled means that we detected that our egress ssh client emitted a warning telling us that the remote keys changed, and also that password authentication has been disabled.
Amount of seconds (with a millisecond precision) between the session open and the session close.
These logs are produced when Perl emits a warning (using the
or respectively when Perl halts abruptly due to a
This should not happen during nominal use. You might want to keep a look on those messages if they're produced.
Dec 28 11:12:26 myhostname bastion: warn uniqid="a46e51b5dce4" version="3.01.02" pid="3308212" ppid="3308206" sysuser="lechuck" sudo_user="" uid="99994" gid="99994" msg="Cannot find termcap: TERM not set at /usr/share/perl/5.28/Term/ReadLine.pm line 379. " program="/opt/bastion/bin/shell/osh.pl" cmdline="-c^-i ssh email@example.com id" trace=" at /opt/bastion/bin/shell/../../lib/perl/OVH/Bastion.pm line 41. OVH::Bastion::__ANON__(\"Cannot find termcap: TERM not set at /usr/share/perl/5.28/Ter\"...) called at /usr/share/perl/5.28/Term/ReadLine.pm line 391 Term::ReadLine::TermCap::ornaments(Term::ReadLine::Stub=ARRAY(0x5575da36b690), 1) called at /opt/bastion/lib/perl/OVH/Bastion/interactive.inc line 77 OVH::Bastion::interactive(\"realOptions\", \"-i ssh root\\@172.17.0.222 id\"..., \"timeoutHandler\", CODE(0x5575da15aa78), \"self\", \"lechuck\") called at /opt/bastion/bin/shell/osh.pl line 485 "
This is the message used as a parameter to the
Contains the name of the currently running program (first parameter of
Contains the full command line passed to the currently running program (remaining parameters of
execve()). The command-line fields are separated by
The call trace leading to this
These logs are produced when some known portion of code (including libraries) called
but in a known case that can happen during nominal use.
Don't use these logs to directly trigger an alert, but you can keep an eye on those, as e.g. an unusually
high number of occurences in a short time may be a weak signal that somebody or something is misbehaving.
The fields are the same than the ones specified above for warn and die.
These logs are produced when some portion of the code encounters an minor issue that is worth logging, to e.g. help debugging an issue or understanding what happened in a specific use-case, for example if a user-session ended abruptly. These logs are not the result of an error on the bastion configuration and don't mandate immediate admin attention.
Dec 25 14:56:11 myhostname bastion: code-info uniqid="98d2f32b1a2d" version="3.07.00" pid="3708843" ppid="3708842" sysuser="lechuck" sudo_user="" uid="8423" gid="8423" msg="execute(): error while syswriting(Broken pipe) on stderr, aborting this cycle"
A human-readable text describing the error
These logs are produced when some portion of the code encounters an unexpected issue or abnormality that is worth logging. They'll usually not be emitted due to a bad user interaction, but rather if the bastion is misconfigured, or for anything that might need some attention or fixing from the admins.
Dec 28 11:12:26 myhostname bastion: code-warning uniqid="ffee33abd1ba" version="3.01.03" pid="3709643" ppid="3709642" sysuser="lechuck" sudo_user="" uid="8423" gid="8423" msg="Configuration error for plugin selfGenerateEgressKey on the 'disabled' key: expected a boolean, casted 'no' into false"
A human-readable text describing the error
This log is produced when an access control list is modified, either personal accesses of an account, or a group servers list.
Dec 28 11:12:26 myhostname bastion: acl uniqid="f25fe71c6635" version="3.01.02" pid="3116604" ppid="3116603" sysuser="keysomegroup" sudo_user="lechuck" uid="10006" gid="10057" action="add" type="group" group="somegroup" account="" user="root" ip="172.16.2.2" port="22" ttl="" force_key="" comment=""
Will be either add if an access is added, or del if an access is removed
Will be either group if we're modifying a group server list, in which case the group field will be filled, or account if we're modifying personal accesses of an account, in which case the account field will be filled
If type is group, indicates which group servers list has been modified
If type is account, indicates which account personal accesses have been modified
The remote user part of the access we're adding/removing
The IP or IP block of the access we're adding/removing
The port of the access we're adding/removing
If set, represents the TTL after which the access will automatically be removed
If set, this contains the fingerprint of the key that'll be used for this access
Any comment set by the user adding/removing the access
This log is produced when one of a group's role list is modified: either an owner, member, guest, aclkeeper or gatekeeper.
Dec 28 11:12:26 myhostname bastion: membership uniqid="a00993ec6767" version="3.01.02" pid="1072528" ppid="1072497" sysuser="lechuck" sudo_user="" uid="2070" gid="2070" action="add" type="member" group="monkeys" account="stan" self="lechuck" user="" host="" port="" ttl=""
Either add when an account is added to a group role list, or del when an account is removed
Type of the role list we're modifying, either member, aclkeeper, gatekeeper, guest or owner
Group whose one of the role list is being modified
Account being added/removed to/from the group role list
Account performing the change
When type is guest, the remote user part of the access we're adding/removing
When type is guest, the IP or IP block part of the access we're adding/removing
When type is guest, the port of the access we're adding/removing
When type is guest and action is add, if a TTL has been specified for the access, it appears here
This log is produced when an important security event has occurred, such as when an admin impersonates another user, or when a super owner uses his implicit global ownership to modify a group. You might want to watch those closely.
Dec 28 11:12:26 myhostname bastion: security uniqid="601a17b5e5ba" version="3.01.03" pid="20519" ppid="20518" sysuser="lechuck" sudo_user="" uid="2604" gid="2604" type="admin-ssh-as" account="lechuck" sudo-as="gthreepw" plugin="ssh" params="--user root --host supersecretserver.example.org --port 22"
Type of the security event that occurred. Can be:
admin-ssh-as: an admin impersonated another user to establish an egress connection
admin-sudo: an admin impersonated another user and launched an osh plugin on their behalf
superowner-override: a super owner used his implicit ownership on all groups to modify a group
Account that emitted the security event
When type is admin-ssh-as or admin-sudo, name of the account that was impersonated
Name of the osh plugin that was launched
Parameters passed to the plugin, or command line used to establish the egress connection
This log is produced when a group is created or deleted. Note that membership modifications are referenced with the membership type instead, see above.
Dec 28 11:12:26 myhostname bastion: group uniqid="56f321fb3e58" version="3.01.03" pid="1325901" ppid="1325900" sysuser="root" sudo_user="lechuck" uid="0" gid="0" action="create" group="themonkeys" owner="stan" egress_ssh_key_algorithm="ed25519" egress_ssh_key_size="256" egress_ssh_key_encrypted="false"
Either create or delete, indicating whether the group has just been created or deleted
The group name being created or deleted
When action is create, the name of the owner of the new group we're creating
- egress_ssh_key_algorithm, egress_ssh_key_size
When action is create, the algorithm (and size) used to generate the first pair of SSH keys, can be empty if
When action is create, if a key was generated, will be true if
--encryptedhas been used, false otherwise
This log is produced when an account is created or deleted.
Dec 21 14:30:26 myhostname bastion: account uniqid="ee4c91000b75" version="3.01.02" pid="537253" ppid="537252" sysuser="root" sudo_user="lechuck" uid="0" gid="0" action="create" account="stan" account_uid="8431" public_key="ssh-rsa AAAAB[...]" always_active="false" uid_auto="false" osh_only="false" immutable_key="false" comment="CREATED_BY=lechuck BASTION_VERSION=3.01.02 CREATION_TIME=Mon Dec 21 14:30:26 2020 CREATION_TIMESTAMP=1608561026 COMMENT=requested_by_the_sword_master_of_melee_island_see_ticket_no_1337"
Either create or delete, indicating whether the account has just been created or deleted
The account name being created or deleted
When action is create, the UID associated corresponding to the account we're creating
When action is create, the public key we've generated for the new account
- always_active, uid_auto, osh_only, immutable_key
When action is create, true if the corresponding option was specified (
--immutable-key), false otherwise
When action is create, the comment specified at creation if any, with some metadata that'll be stored in the account properties (created_by, bastion_version, creation_time, creation_timestamp)
When action is delete, the name of the tty group specific to this account that was deleted at the same time
If you use
syslog-ng and installed the provided templates (which is the default if you used
--new-install option to the install script), you'll have 4 files in your system log directory:
This is where all the bastion usage logs will be written. All the above message types can be found in this file.
This is where Perl crashes will be logged, with the message type
die. On a production bastion, this file should normally be empty.
This is where Perl warnings will be logged, with the message type
warning. On a production bastion, this file should mostly be empty.
This is where all the satellite scripts (mostly found in the
bin/cron/directory) will log their output.
A syslog message will always match the following generic format:
SYSLOG_TIME SYSLOG_HOST bastion: MSGTYPE field1="value1" field2="second value" ...
Where SYSLOG_TIME is the usual datetime field added by your local syslog daemon, and SYSLOG_HOST the hostname of the local machine. The MSGTYPE indicates the message type of the log line (the list of types is further below). Then, a possibly long list of fields with quoted values, depending on the MSGTYPE.
An example follows:
Dec 28 11:14:23 myhostname bastion: code-warning uniqid="e192fce7553a" version="3.01.03" pid="18803" ppid="18802" sysuser="gthreepw" sudo_user="" uid="99998" gid="99998" msg="Configuration error: specified adminAccounts 'joe' is not a valid account, ignoring"
In that case, the MSGTYPE is
code-warning, and we have a few field/value couples with some metadata of interest,
followed by a human-readable message, indicated by the
Only satellite scripts will miss the field/value construction, which will just be replaced by a plain text message.
These logs are stored in
/var/log/bastion/bastion-scripts.log by default.
If you don't or can't use Syslog, the bastion can create and use access log files on its own, without relying on a syslog daemon. Note that you can enable both syslog and these access logs, if you want.
When enabled, a single log file will be used, located in
/home/logkeeper/global-log-YYYYMM.log. There will be one file per month. Note that it can grow quite large if you have a busy bastion.
When enabled, one log file per account will be used, located in
/home/USER/USER-log-YYYYMM.log. There will be one file per month.
If both options are enabled, it means that every access log will be logged twice, to two different locations. If you also enabled syslog, it's even three times!
When enabled, a global sqlite database will be created in
/home/logkeeper/global-log-YYYYMM.sqlite. It'll contain one row per access (created at the same time the open log is emitted). The following columns exist: id, timestamp, account, cmdtype, allowed, ipfrom, ipto, portto, user, plugin, uniqid. Refer to the open log description to get the meaning of each column.
When enabled, an sqlite database per account will be created in
/home/USER/USER-log-YYYYMM.sqlite. It'll contain one row per access (created at the same time the open log is emitted), and the same row will be updated by the close event when it is emitted. The following columns exist: id, timestamp, timestampusec, account, cmdtype, allowed, hostfrom, ipfrom, bastionip, bastionport, hostto, ipto, portto, user, plugin, ttyrecfilee, params, timestampend, timestampendusec, returnvalue, comment, uniqid. Refer to the open log and close log descriptions to get the meaning of each column. Note that the enableAccountSqlLog option is required if you want the selfListSessions and selfPlaySession plugins to work, as they use this database.
Note that enabling these on a very busy bastion (several new connections per second) can create lock contention, especially on the global log: ensure you have a fast storage. In any case, if a connection can't get the lock after a few seconds, it'll proceed anyway, and skip writing the sql log. In that case, if you enabled syslog or local access logs, the globalsql and/or the accountsql field will contain the error detail.
Every egress connection is started under
ttyrec, which means that everything appearing on the console is recorded.
If a password is asked by some program, for example, and typing the password prints '*' or doesn't print
anything at all, this won't be recorded. This is by design. In other words, the keystrokes are not recorded,
except if they produce something on the screen.
The ttyrec files location is always
/home/USER/ttyrec/REMOTEIP/file.ttyrec, where the actual file.ttyrec
name can be configured by the ttyrecFilenameFormat option.
By default, it'll contain the date, time, account, remote ip, port and user used to start the egress connection,
as well as the uniqid, for easier correlation between all the logs produced by the same connection.
Note that for long connections, or connections producing a lot of output, ttyrec files will be transparently rotated,
without interrupting the connection.
This is to avoid ending up with ttyrec files of several gigabytes that would still be opened, written to,
hence impossible to compress, encrypt, and push to an escrow filer.
The uniqid will be the same for all the ttyrec files corresponding to the same connection.
To play ttyrec files, you can either use selfPlaySession for yourself, or,
for admins having local access to the bastion machine, the
ttyplay program can be used.
Another software, perhaps more powerful than ttyplay, can also be used:
aka "It's PlayBack Time", by the PuTTY author.
It can do more advanced things such as look for words appearing on any frame recorded in the ttyrec file,
play files using a logarithmic speed, or display an OSD with the exact time output you're seeing has appeared.
As ttyrec is a well-known format that has been around for a while,
there are a bunch of other programs you can use to read or convert these files.