logging shell commands to syslog on secure systems

I had recently come across a blog post describing methods for capturing commands entered on the command line, and recording them to syslog.  Either by function() or by patching the actual shell itself.   I found this article because I was asked by my boss to find a way to add CLI logging to some hosts on our network, to support audits and accountability.

Some of the environments I work on are more secure than usual.  In a typical corporate environment, whether internet connected or not, there is generally no need or requirements to use system auditing to track all user actions.  Some government systems, whether classified or not, do require this, and some commercial systems in regulated industries, or who service government agencies, also require this level of auditing and accountability.  In some cases it can be a smart idea for non-regulated systemd.  For instance, if you're a managed services company that uses a team of operators to manage multiple customer environments, there may be some value to tracking user activity. 

Most operating environments these days come with some sort of auditing facility, however I have found that these are usually fairly unintuitive, and most people that implement auditing do so by following a How-To, and then end up not actually having a SME on staff when things do go wrong.  Audit logs can also consume a lot of space, so lots of sysadmins just delete old audit logs in an effort to reclaim disk space.

One easy, and portable, way to quickly and intuitively audit user activity involves using patched shells to send all the commands run to syslog.  I should note that there are a few weaknesses in logging all commands to syslog, such as password exposure.  Some people do put passwords in the command line of such tools as ldapsearch, or mysql, or sqlplus.  Those passwords will then be recorded in plain-text in your system logs.

And there are always ways to work around being logged, like running a shell that doesn't log to syslog, which can be done as simply as by uploading your own, non-logging, shell and running it. 

Aside from the weaknesses outlined above, though, in an environment where users are not malicious, and where team members can find themselves on any of a number of systems at any particular time, logging user can provide very valuable context in a familiar way.  And quickly, too.

Using syslogging shells is simply a tool like any other.  It doesn't replace real system auditing, but it definitely has it's place.

GNU Bash 4.1 has all the code to enable command logging, simply by editing the config-top.h file. Just change:

/* Define if you want each line saved to the history list in bashhist.c:
bash_add_history() to be sent to syslog(). */
/* #define SYSLOG_HISTORY */
#if defined (SYSLOG_HISTORY)
# define SYSLOG_FACILITY LOG_USER
# define SYSLOG_LEVEL LOG_INFO
#endif

to:

/* Define if you want each line saved to the history list in bashhist.c:
bash_add_history() to be sent to syslog(). */
#define SYSLOG_HISTORY
#if defined (SYSLOG_HISTORY)
# define SYSLOG_FACILITY LOG_USER
# define SYSLOG_LEVEL LOG_INFO
#endif

And all commands in interactive shells are logged. (don't forget to add the other 9 official bash patches to get to code level 4.1.9)

One thing I did notice is that in Solaris, the PID was being logged with the log entry to syslog, however this was not the case in linux.  Rather the PID was being logged by the log entry %s itself.

  if (strlen(line) < SYSLOG_MAXLEN)
syslog (SYSLOG_FACILITY|SYSLOG_LEVEL, "HISTORY: PID=%d UID=%d %s",
getpid(), current_user.uid, line);

Resulting in log entries like:

Dec  7 23:13:02 linux bash: HISTORY: PID=1752 UID=1001 ls

I don't really like that format, either. I'd rather see usernames and commands, and have the pid over on the left with the 'bash:'. This was a pretty simple change in code to:

  openlog("bash",LOG_PID,SYSLOG_FACILITY);
if (strlen(line) < SYSLOG_MAXLEN)
syslog (SYSLOG_LEVEL, "[%s] %s", current_user.user_name, line);

This results in log entries that look like:

Dec  7 23:26:39 linux bash[1846]: [tkennedy] ls

To me, this is a much more readable log file. Perhaps that's because I'm used to the log format that the BOFH patched tcsh shell, which we also use, uses. Now bash and tcsh log in identical formats. Our users have been informed that bash and tcsh are acceptable for interactive shells on Linux, and there were no exceptions. On Solaris we encourage the use of bash or tcsh for interactive shells in the hopes that consistency lends itself to stability, although we use the RBAC aware pf- shells for role accounts like 'oracle' which encourage ksh.

Here's my patch to bashhist.c that logs entries the way I like them: bashhist.c.patch

diskread: reading beyond end of ramdisk (& how I recovered)

We had to do a maintenance to replace a NEM module in a Sun Blade 8000 Modular System.

Two of my team mates went on down to the datacenter on other business and graciously offered to SWAP the NEM for me. The pulled the old one out, stuck the new one in.

That's as simple as it should have been.

Should have been. I wish. Instead, the chassis started to freak out, cycling it's power over and over, and somehow was taking the CMM with it. In between one set of cycles, I was able to connect to the CMM via console and paste in a bunch of commands to shut down chassis power. I let it sit for a moment, then began to power up the system. First the chassis, then the individual blades. One blade came up, no problem. The next two, though, were very much less than happy, spitting out errors like:

diskread: reading beyond end of ramdisk
start = 0x2000, size = 0x2000
failed to read superblock
diskread: reading beyond end of ramdisk
start = 0x2000, size = 0x2000
failed to read superblock
panic: cannot mount boot archive
Press any key to reboot

The GRUB menu was coming up OK, though, so I pressed the trusty any key, booted into Solaris 10 Failsafe mode. This was no picnic either.

SunOS Release 5.10 Version Generic_120012-14 32-bit
Copyright 1983-2007 Sun Microsystems, Inc. All rights reserved.
Use is subject to license terms.
Booting to milestone "milestone/single-user:default".
Configuring devices.
Searching for installed OS instances...
NOTICE: /a: unexpected free inode 5825, run fsck(1M)
/dev/dsk/c2t0d0s0 is under md control, skipping.
To manually recover the boot archive on a root mirror,mount the first
side (the one that the system boots from) and run:

bootadm update-archive -R

umount: /a busy

No installed OS instance found.

Starting shell.
#

My immediate thought was "WTF? No installed OS instance found?" Closer inspection revealed that it had in fact found two possibilities, but one c2t1d0s0 was inconsistent and needed a fsck, and the second c2t1d0s0 was under md control, and so being skipped.

An fsck of /dev/dsk/c2t0d0s0 revealed a few inconsistencies. Here's an example. I think this was actually the 3rd of 4 fscks I ran on this dev:

bash-3.00# fsck /dev/dsk/c2t0d0s0
** /dev/rdsk/c2t0d0s0
** Last Mounted on /
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3a - Check Connectivity
** Phase 3b - Verify Shadows/ACLs
** Phase 4 - Check Reference Counts
UNREF FILE I=1457 OWNER=root MODE=100644
SIZE=657 MTIME=May 15 18:01 2008
RECONNECT? y

UNREF FILE I=1458 OWNER=root MODE=100644
SIZE=675 MTIME=May 15 18:06 2008
RECONNECT? y

** Phase 5 - Check Cylinder Groups

CORRECT BAD CG SUMMARIES? y

CORRECTED SUMMARY FOR CG 0
FRAG BITMAP WRONG
FIX? y

FRAG BITMAP WRONG (CORRECTED)
CORRECTED SUMMARY FOR CG 4
CORRECTED SUMMARY FOR CG 12
CORRECTED SUMMARY FOR CG 30
CORRECTED SUMMARY FOR CG 70
CORRECT GLOBAL SUMMARY
SALVAGE? y

Log was discarded, updating cyl groups
46737 files, 1720899 used, 24099860 free (21460 frags, 3009800 blocks, 0.1%
fragmentation)

***** FILE SYSTEM WAS MODIFIED *****

So far, so good. Let's reboot, and see if we an come up in a multi-user state. So ... reboot ... wait ... wait ...

CRAP! Same panic as our previous boot. We're missing something. A further delve into google reveals that I need to recreate the ramdisks for boot. A boot into failsafe mode again, allows me to fsck c2t0d0s0, which is mounted on /a, and remount it -o rw. bootadm update-archive fails, due to fs inconsistency. Another fcsk, we're in single user, nothing is using that disk, so I just ran the fsck without remounting -o ro. Now, let's skip bootadm and just move straight along to /boot/solaris/bin/create_ramdisk.

bash-3.00# /boot/solaris/bin/create_ramdisk -R /a
Creating ram disk for /a
updating /a/platform/i86pc/boot_archive...this may take a minute

That's it! That's the little piece of magic that fixed it. After that, I was able to reboot, and the server came right up into runlevel 3. Not without a few minor errors, but at least it was up.

SunOS Release 5.10 Version Generic_127112-11 64-bit
Copyright 1983-2008 Sun Microsystems, Inc. All rights reserved.
Use is subject to license terms.
Hostname: generic
NOTICE: /: unexpected free inode 9193, run fsck(1M) -o f
NOTICE: /: unexpected free inode 5961, run fsck(1M) -o f
WARNING: /: unexpected allocated inode 9637, run fsck(1M) -o f
Loading smf(5) service descriptions: 1/1
/dev/md/rdsk/d60 is clean
/dev/md/rdsk/d30 is clean
/dev/md/rdsk/d20 is clean

generic console login:

At this point it was pretty simple to complete the fix, which, not wanting to reboot into failsafe mode and fsck a bunch more to recover from the unexpected free and allocated inodes, I wrote a script to: by turns, detach each have of the root mirror, clear the detached metadevice, newfs the raw device, re-create the metadevice, and attach it once again to the mirror. Let it sit long enough to complete the resync, and repeat the same steps on the other half of the mirror.

#!/bin/sh
#
# fix-mirror.sh
#
# 05-16-2008 Tim Kennedy
#
# This script will take one argument, which should be the
# metadevice of the mirror you want to rebuild. This script
# will determine the Submirrors, and one at a time, detach,
# clear, newfs, re-init, and reattach them.
# For me this has solved problems with ailing filesystems,
# while replacement storage is procured.
#
# YMMV. Use at your own risk. This is not in any way to
# be considered a Sun Microsystems product, and is not in
# any way supported by Sun Microsystems.
#
 
PATH=/usr/bin:/usr/sbin
export PATH
 
MIRROR=$1
 
check_return () {
RETURN=$1
if [ $RETURN = 0 ]; then
printf "%-6s\n" "[ok]"
else
printf "%-6s\n" "[err]"
echo
echo "please check the last step manually to see why it failed."
echo
exit 1
fi
}
 
for m in `metastat $MIRROR | grep "Submirror of $MIRROR" | cut -d: -f1`; do
echo "Found Submirror $m"
DEVICE=`metastat -p $m | awk '{print $NF}'`
printf "%-72s" " -- metadetach $MIRROR $m"
metadetach $MIRROR $m >/dev/null 2>&1
check_return $?
printf "%-72s" " -- metaclear $m"
metaclear $m >/dev/null 2>&1
check_return $?
printf "%-72s" " -- newfs /dev/rdsk/$DEVICE"
echo y | newfs /dev/rdsk/$DEVICE >/dev/null 2>&1
check_return $?
printf "%-72s" " -- metainit $m 1 1 /dev/dsk/$DEVICE"
metainit $m 1 1 /dev/dsk/$DEVICE >/dev/null 2>&1
check_return $?
printf "%-72s" " -- metattach $MIRROR $m"
metattach $MIRROR $m >/dev/null 2>&1
check_return $?
printf "%-72s" " -- checking resync status before continuing "
while [ 1 ]; do
STATE=`metastat -c $MIRROR | head -1 | grep resync`
if [ "x${STATE}" = "x" ]; then
printf "%-6s\n" "[ok]"
break;
else
sleep 60
fi
done
done

Now these blades are happy once again. We'll see how long that lasts or if they continue to have problems of any sort. My hope is for the former.

Have a good weekend.

solaris 10, sun cluster, zfs, and zones not creating devices

I had this strange problem where zones weren't properly creating devices. This is on a newly Jumpstarted Solaris 10, Sun Cluster 3.2, cluster. The strange part is that we have 8 other clusters that all run zones, and none of them have the problem. I thought it might have been something wierd with ZFS, but other zones on ZFS roots can create devices.

As it turns out, the Jumpstart server that we built this cluster with is not as 'up to date' as our 'main' Jumpstart server, and was not patching new builds up to the latest kernel patch.

Updating the system with kernel patch 127111-11 resolves this issue. This patch patches a ton of stuff.

The specific bug that hit us was bugID 6608977 can't add device to non-global zone in S10 update 4.

That bug was actually fixed in 127111-03 but 127111-11 fixes a ton of stuff.

Using Solaris 10 Update 3, Sun Cluster 3.2, Zones, & ZFS in a Multi-Node Cluster of Sun Fire T-2000s

It all started with a conference call with one of our customers. We wanted a way to set up some highly available systems that could be used for various beta or QA purposes, or production services, or anywhere in between as needed. We also wanted a way to maximize the resources. We had 4 servers available to us, all Sun Fire T-2000s. If we used them as straight servers, they'd be great at anything they do, right? 8 cores, 4 threads per core, 32GB of RAM. Nice. Capable of running dozens of zones without skipping a beat. Perhaps even hundreds of zones.

Zones make perfect development boxes, right? You can blow them away and re-install them in a matter of minutes, or even seconds on ZFS. Zones also do pretty good as production environments as well. We're currently using a large number of zones in production, to supply a variety of services.

Zones on ZFS make particularly good dev boxes because you can take frequent snapshots and roll back as desired.

** Zones with their zoneroot on ZFS do encounter bug #6356600, which relates to how the live upgrade scratch zone used for installing packages into local zones can't access ZFS filesystems to upgrade zones with a ZFS zoneroot.

Sun Cluster 3.2 introduced support for ZFS as a failover filesystem, and for failover zones as well. We decided to make use of both of these features.

We built a 4-node cluster out of the 4 T-2000s, and began exporting individual disks from our SAN. Put 3 disks in a ZFS pool as a raidz filesystem, and installed the zone root at a ratio of 1 zone per zpool. (We're still doing some testing with our SAN and comparing performance of ZFS on individual disks, or ZFS on a RAID5 LUN exported by the SAN, but so far the way we're doing it is working nicely.)

So we built the cluster, and got it all configured and running. We then installed the first zone onto the ZFS pool. Then I copied the relevant portions of the zones configuration (in /etc/zones/*) to the other nodes in the cluster.

We then created a resource group in Sun Cluster 3.2, and added the zone into the resource group. We also added the ZFS pool into the resource group as an HA-Storage resource, and created a quick set of control scripts to start and stop the zone. The zone itself takes care of bringing up it's ip addresses, and starting the various applications installed within.

End result: Highly available servers, on a failover basis, that take less than 30 seconds to fail over from one host to another.

So far it's working really well. We're already getting more requests to build more of these multi-noded clusters, with zone/zpool combo's as the resource group. It's been a great solution for us.