Sunday, February 14, 2010

Butterfly effect

A couple of weeks ago we put together a maintenance release for the old SCB 1.x line. It contained only tiny fixes and security updates for the 3rd party packages we use in it, but as every release, it had to go under a thorough release test. Everything went fine, everything seemed to work as it was supposed to and we were about to press that shiny red release button, when I recalled one of the testers complaining about some weird lock-up problems days earlier. At that time we didn't really pay much attention to it as it seemed like it was caused by a confusion in the test network (we attached multiple machines to the HA link), but still, it seemed like a good idea to try some hard resets on the VirtualBox machine I was doing the release test on. And then came what caused me to go home at 1AM instead of 5 in the afternoon and started to make me think about that Bradbury novel...

After resetting the machine it started to boot up fine, but after a while it stuck displaying the message "Waiting for DRBD to become consistent..." and refused to go any further. It's something we had put in the bootup process ourselves: this is where we wait for the HA nodes to become in sync after setting up HA operation for the first time or when one of them have been turned off for a longer period of time. But wait, the machine I was testing on wasn't even connected into an HA cluster! What is it waiting for then? So I started to do some serious debugging.

In our scripts, we mostly use an own deamon called "xcbdaemon" to fetch information from the HA nodes through XMLRPC calls. When we want to query information -- in this case, the DRBD status -- from the node we're currently running on, we connect to the daemon over the "lo" interface. This is where the problems started: we didn't have a "lo" interface, so the querying couldn't complete and, as a safety measure, we did not let the system to boot in an inconsistent HA state to avoid split-brain situations. I started to look throught the previous boot messages to find out what could've caused it, and I found it telling me it wouldn't bring up the "lo" interface as it's already up. What the hell?

It turns out that /etc/network/run contains the entry "lo=lo" in it at boot time and this what makes the bootscript think the interface is already set up. But /etc/network/run is supposed to be on a tmpfs so it should be emptied after a reboot...weird. What makes this directory to be on a tmpfs is the postinst script of the ifupdown package. I'm going to copy it here to let you see the, well, not too simple logic it uses to make that happen:


# Create /etc/network/run
if [ "$1" = configure -a ! -d /etc/network/run ]; then
if [ -e /etc/network/run -o -L /etc/network/run ]; then
echo "Renaming non-directory /etc/network/run to run.dpkg-old..."
mv /etc/network/run /etc/network/run.dpkg-old
fi

# The best choice is to use /dev/shm/network
#
# If we can't use that, we'll just make /etc/network/run a directory,
# unless we're upgrading, in which case we'll just keep ifstate where it
# is, by making /etc/network/run a symlink to /etc/network.

WHAT_TO_USE=devshm

if [ ! -d /dev/shm -o ! -w /dev/shm -o ! -r /proc/mounts ]; then
WHAT_TO_USE=owndir
elif ! grep -qs "^tmpfs[[:space:]]\+/dev/shm[[:space:]]\+tmpfs[[:space:]]\+\([^[:space:]]\+,\)\?rw" /proc/mounts
then
WHAT_TO_USE=owndir
elif grep -qs '[[:space:]]/dev[[:space:]]devfs[[:space:]]' /proc/mounts; then
WHAT_TO_USE=owndir
fi

# Check for available space if we are using devshm
if [ "$WHAT_TO_USE" = devshm ]; then
SPACE=`df -k /dev/shm | tail -1 | awk '{if ($4 ~ /%/) { print $3 } else { print $4 } }'`
if [ "$SPACE" -le 0 ]; then
WHAT_TO_USE=owndir
fi
fi

if [ "$WHAT_TO_USE" = owndir -a -e /etc/network/ifstate ]; then
WHAT_TO_USE=etcnetwork
fi

if [ "$WHAT_TO_USE" = devshm ]
then
[ -d /dev/shm/network ] || mkdir /dev/shm/network
ln -s /dev/shm/network /etc/network/run
elif [ "$WHAT_TO_USE" = "owndir" ]; then
mkdir /etc/network/run
else
ln -s . /etc/network/run
fi
fi
As you can see, it contains multiple ifs that could evaluate in the wrong way and make the setup fail, so I started to hunt down the various possibilites one-by-one.

The build of an SCB firmware starts by creating a chroot using debootstrap and then installing the necessary packages and our code on it. I started the build process and stopped at various phases to see when does it go wrong. It turned out that ifupdown is installed right at the beginning during the run of debootstrap and /etc/network/run is already wrong by that time. I started to check the ifs in the postinst script: we have /proc, we have /dev/shm, no /etc/network/run is there, but... oh yeah. /dev/shm is not mounted as a tmpfs on the build server, so the postinst script just says he's sorry and messes up our whole system. I gave out the single mount command needed, rebuilt the firmware and everything was working fine.

Let me summarize this once again: a temporary file system was not mounted on the build server, and, as a result, a standalone Shell Control Box froze at boot signalling an HA-related problem. Talk about ripple effects...

Monday, February 1, 2010

Graduation and the sales kick-off meeting

I haven't had the time to brag about it last week, but on last Monday I managed to defend my thesis and graduate to finally become a certified software engineer. Having spent, well, quite a bit more time in the programme than originally planned and cca. 5 years working in IT, it was high time it happened.

It was a great opportunity to celebrate it at the sales kick-off conference we held at the end of the week. I gave a presentation there about Shell Control Box and held a workshop the next day together with Marton, but the bigger part of the job was to talk with the guests, answer their questions, find out their opinion about our products -- and of course, to make sure they have a good time during their whole stay. I hope we did well in the former (the sales figures of the year will give a good feedback about that), but I'm pretty confident we excelled in the last one: it brought a huge smile to my face when at some point during the party we held Friday evening, a guy from one of the partners from the other end of the world just shouted into my ear while dancing: "BalaBit rocks!" :)

Big up and thanks to everyone involved in the organization of the event -- you did a great job.