And the productivity hits just keep on coming

Evidently it’s company policy that working at home must be requested 24 hours in advance, in writing. So if I find myself unable to come into work for some reason, they want me to stay home and do something else rather than doing useful work on our project. Well, I’ll miss the money, but I think they’re going to miss the work more.

Ice day

When this morning’s alarm clock went off, the radio was saying that Vicki’s place of work was closed because of an overnight ice storm. I looked outside and there was a good half-inch of clear ice on the trees, roads, and my car. And the local news web sites said that the state police were telling people not to drive if they could avoid it.

So I thought about what I’d be doing if I went to work, and it was just working on design documents. I have most of the documents I needed at home, so I thought “screw it” and decided to stay home.

I wanted to email people to tell them that I was going to do that, and I only had a few of their addresses. So I emailed the ones I had, and one of them emailed my new official direct supervisor (even though I really get my job assignments and direct supervision from somebody else, but she signs my time sheets).

She wrote me back. She’s evidently mad that I didn’t follow her new procedure, and phoned her for permission *before* I decided to stay home. In the past, I’ve always been trusted to work at home if I had work that could be done at home, so this seems like a real lack of trust on her part. But then again she’s new to the project and doesn’t know any of us that well – plus she has little to no day-to-day contact with us developers, so maybe she doesn’t know us well enough to know who to trust.

So instead of having a nice day at home where I could work productively but in a relaxed environment, I had to struggle to produce work while worrying if I’d just jeopardized my job.

Just for the record, I got more work done than I would have if I’d been at work.

The ultimate Heisenbug?

We’ve got a problem that happens apparently at random times at a few customer sites, but which we’ve been unable to reproduce in the lab. I’m not sure if that means it’s a Heisenbug or just a really nasty Bohr-bug.

The part of the system that is affected are three programs:

  • One that generates events, called “tixd
  • One that is responsible for collecting events from all the programs in the system (not just these three) and delivering them to subscribers, called the “EventBroker” or “eb
  • One that subscribes to the events that the “tixd” generates, which we call the “scheduled

What has been happening on these customer sites is that after days or weeks of proper operation, for no apparent reason, the “tixd” would say that it’s generating an event, but the “scheduled” wasn’t getting them any more. The customer would notice the problem, sometimes a day or two later, complain that things weren’t happening that were supposed to happen, our service people would restart the whole system, and everything would start working again.

This bug has been happening for ages now, and every time I get called in to look at their logs because I wrote the “scheduled” and all the fingers point to me. But I couldn’t find any reason why “scheduled” would stop responding to events, or would unsubscribe from events. A few builds ago, Tom put some debug into his “eb” that would log every event that came in and which subscribers it was being delivered to. He also logged subscribes and unsubscribes. And so we waited.

Today, it finally happened again. And this time, I’ve got the logs that show:

  • At 6am, an event is generated by the tixd, and the eb delivers it to the subscriber scheduled
  • Between 10am and 11am, there is a flurry of event subscribes and unsubscribes, all unrelated to scheduled. But some of these unsubscribes are caused when events are being delivered to subscribers that have exited without unsubscribing.
  • At about 1am, there is another event generated by the tixd, and the eb receives it but says there are no subscribers found.

At this point, because the eb log shows no unsubscribe coming from scheduled, I’d say it’s not my bug and pass it off to Tom, the author of the eb. But unfortunately, my employer declined to renew Tom’s contract at the end of last year, so he no longer works here. He dodged this bullet by only 5 days. And so I’ve got to figure out why this is happening. Lucky me.

Another damn failure on my colo box

Yesterday I had a panic attack – suddenly a certain repository of binary files was empty where it had been nearly 300Gb a few hours previously. I knew that Vicki was uploading some stuff to it today using an “ncftpput” command that I’d shown her but which I knew she didn’t understand what each command line argument meant. So I’m sorry to say my first reaction was “I bet she somehow wiped it”. But I looked in her ~/.ncftp/spool/log file and couldn’t see anything unusual. I guess I owe her an apology for that thought.

I looked on the domU, and “df” showed the partition still mounted, and still 91% full. But nothing showed up to “ls”. I unmounted it and shut off the nightly backups so that it doesn’t delete the backup. “fsck.ext3 /dev/hdb” gave an error about a zero length partition. Then I thought I should probably be doing this on the dom0, and so I logged into it and had the same error with “fsck.ext3 /dev/hdb1”. “fsck -l /dev/hdb” on that entire drive showed that it didn’t think the drive was there at all. Oh oh. Moment of panic time – one of the other domUs has some of its disk space on that drive as well, thanks to LVM. I wonder what’s screwing up on his domU if it can’t get to some of its disk space. Time to shut them all down and reboot.

I did an “xm console xen1” to connect to my domU and that’s where I saw the oh-so-familiar ext3 errors. But everything shut down relatively cleanly and rebooted. I saw one message in the log files about resetting the ide0 controller, which I’m not sure was caused by or the cause of the problem. And after the reboot, all 300Gb of files were back. Thank goodness, because the upload bandwidth I’ve got at home these days means it would have taken months to get that partition restored from my backup.

This partition that screwed up this time is a normal primary disk partition, not an LVM logical volume, and on a different physical drive than the other failures, so at least I’ve eliminated LVM and the disk hardware as a cause. But that leaves the IDE controller and Xen.

I can’t wait for my new 1U server to come. Still not sure whether I should try Xen again or VMWare. VMWare probably isn’t as fast and it’s a lot more difficult to manage without getting the for-pay version, but at least it’s “ready for prime time”.

What a pain in the ass

This morning while perusing my logwatch mails I see a strange result from the script that is supposed to email me with the day’s changes from my DAFIF Replacement wiki. It was complaining about a missing perl module in the twiki/bin directory. So I look, and the twiki/bin directory is totally empty.

Some low life found a vulnerability in TWiki, and used it to remove everything in twiki/bin. I guess I should count myself lucky that he didn’t find any way to remove or corrupt other files that were writable by the web browser, since he managed to do it *before* the nightly backup ran.

I was running a pretty ancient version of TWiki, so it was probably long past time to upgrade. The upgrade to 4.0.5 seems to have been pretty painless. But it’s not what I wanted to be doing this morning.