The Life of a Sysadmin

Wednesday, 5am: 2yr-old son wakes up and starts to shout. I go into his room to pick him up and step into a pool of cold vomit. He seems fine.

Thursday, 5:15am: 2yr-old son wakes up and starts to shout. I go into his room to pick him up and step into a pool of cold vomit. I stay home a few hours to clean up the carpet. He seems fine.

Friday, 6:10am: 2yr-old son wakes up and starts to shout. I go into his room to pick him up and turn on the light. I avoid stepping into a pool of cold vomit. 4yr-old son wakes up and starts to throw up; he throws up every half hour 'til noon. I stay home to take care of the kids. We put a towel on the carpet by the head of 2yr-old son's crib. 4yr-old son grey-green most of the day but picks up after nap time. 2yr-old son seems fine. We watch fourteen hours of television.

Saturday, 2am: 2yr-old son wakes up and starts to shout. Clara goes down and finds him in a pool of vomit within the crib. She sleeps in the rocking chair with him 'til 7am. 4yr-old son much better ("I feel MUCH better today!" he says). 2yr-old son whiny and miserable. Clara and I feel like shit and are whiny and miserable. Clara's parents take 4yr-old son for the day. I drive us all to the doctor, worried about how many things are going on right now (night vomits + bug + teething + what the hell else?); dr tells us almost certainly the same bug, but manifesting itself differently in all of us. Clara drives us home while I slump against the car window, cursing the sunlight. 2yr-old son refuses to nap so I hold him in a rocking chair for two hours while reading James Herriot. We watch sixteen hours of television and eat plain crackers dipped in filtered water.

Sunday: 2yr-old son feeling better. He has not thrown up in the night. 4yr-old son feeling even better than yesterday. Clara and I still feel like shit. We take the kids to the park in the morning. 2yr-old son naps on his own. Clara and I gradually improve through the day. We eat plain crackers with salt in the morning, plain crackers with peanut butter in the afternoon, then four pounds of leftover mac and cheese at 8pm. We watch "Office Space" and laugh weakly.

Monday, 4:45am: 2yr-old son wakes up and starts to shout but agrees to go back to sleep. 4yr-old son does the same at 5:45am.

I'm at work today. There was a scheduled power outage in the building that holds our server room. It was set for 7am to 11am; I got in at 6am 'cos I'm a keener and wanted to make sure I had lots of time to swap to the backup website.

Power came back on at 10:30 or so. 10:45 I wandered over to the building to see if that was it; didn't want to rush anyone, but thought it'd be worth asking. There was no one there. Sweet, thinks I, let's head down and turn on some machines. (Most are Sun machines and therefore work just fine remotely; some are older IBM machines, where I haven't figured out how to do IPMI over the network, and some are Dell machines where, whee! who knows how it'll work today?)

Turns out A/C's still off. Call the university folks; turns out someone's still working on it. But they're off for lunch, so no idea just yet how long that'll be. I'll be calling back in an hour to see if we have any idea. If they're working on it 'cos something went wrong, well, that's life. If they're working on it 'cos they had scheduled something, then I'm irritated I wasn't told beforehand. Oh well, we'll see what happens. (Update: Our rooftop A/C failed to come on after the power came back on. A full investigation, with twelve helicopters full of determined journalist-engineers, will be launched tomorrow. THIS GOES ALL THE WAY TO THE TOP, PEOPLE.)

In other news, it wasn't a complete waste of time today:

• I found the Python LDAP module and used it to add a bunch of AutoFS entries to the tree. The simplebrowser.py script included in the examples is quite nice. (Though it does make me wonder why I haven't started using one of the billion-and-three LDAP browser tools instead of a) complaining about phpLDAPadmin or b) trying to remember the syntax for ldapsearch).

• I got to wear my safety shoes.

• Downloading Rocks to try installing it on three old servers haning around.

• Discovered that a workstation's hard drive is failing; fortunately it's not needed right away.

• And, erm, that's it.

Loadsoflinks:

• OpenParliament.ca has opened, and it's 'way cool.

• Via my boss comes this detailed legal analysis of the recent US court ruling against gene patents; interesting stuff

• Shades of O_PONIES (via Bob Plankers)

• Alberta privacy commisioner OKs U of A move to Gmail; must read up on this. I heard about this at LISA '09 from a U of A sysadmin

• A down-to-earth, remarkably non-panicky talk (MP3, overview) on Advanced Persistent Threats. (The Loyal Opposition: here, here and especially here)

• How a Sandwich Makes You Its Bitch in 11 Easy Steps

• Gource and Logstalgia

And just one more thing: my younger son turns two on Tuesday. We had an early party:

Recently I had to track messages to make sure they were being delivered, and this turned out to be much harder than I thought. Some of this is due to the way we have our mail set up, and some of it is just due to confusion (mine) about how Postfix logs things. So in the spirit of Chris Siebenmann, here's my explanation for my future self of how this works.

First, an explanation of the flow of messages at my workplace, whether sent or received from a local network or a remote network:

• Postfix receives the message and passes to SpamAssassin
• SpamAssassin scans the message, then requeues it with Postfix
• Postfix receives the scanned message and delivers it

Here's a log with an example message. It was sent from pepperoni@pepperoni.pizza to otheruser@example.net, which we forward off to ilikesandwiches@club.sandwich. (Rememver the days when you could be assured that "club.sandwich" was a totally bogus TLD?)

   Apr  9 13:25:13 liddy postfix/smtpd[12203]: 4DC3914C086: client=mail.example.com[192.168.0.2]
   Apr  9 13:25:13 liddy postfix/cleanup[12206]: 4DC3914C086: message-id=<deadbeef@example.com>
   Apr  9 13:25:13 liddy postfix/qmgr[995]: 4DC3914C086: from=<pepperoni@pepperoni.pizza>, size=2019, nrcpt=1 (queue active)
   Apr  9 13:25:13 liddy spamd[5110]: spamd: processing message <deadbeef@example.com> for nobody:99
   Apr  9 13:25:13 liddy spamd[5110]: spamd: result: . 0 - scantime=0.2,size=1981,user=nobody,uid=99,required_score=5.0,rhost=localhost.localdomain,raddr=127.0.0.1,rport=42925,mid=<deadbeef@example.com>,autolearn=failed
   Apr  9 13:25:13 liddy postfix/pickup[11886]: 85E1F14C089: uid=99 from=<pepperoni@pepperoni.pizza>
   Apr  9 13:25:13 liddy postfix/cleanup[12206]: 85E1F14C089: message-id=<deadbeef@example.com>
   Apr  9 13:25:13 liddy postfix/pipe[12207]: 4DC3914C086: to=<otheruser@club.sandwich>, orig_to=<ilikesandwiches@example.org>, relay=spamassassin, delay=0.25, delays=0.05/0/0/0.2, dsn=2.0.0, status=sent (delivered via spamassassin service)
   Apr  9 13:25:13 liddy postfix/qmgr[995]: 4DC3914C086: removed
   Apr  9 13:25:13 liddy postfix/qmgr[995]: 85E1F14C089: from=<pepperoni@pepperoni.pizza>, size=2323, nrcpt=1 (queue active)
   Apr  9 13:25:43 liddy postfix/smtp[12212]: 85E1F14C089: to=<otheruser@club.sandwich>, relay=mail-relay.isp.tld[10.0.0.1]:25, delay=30, delays=0.01/0.01/30/0.35, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 92585180F0)
   Apr  9 13:25:43 liddy postfix/qmgr[995]: 85E1F14C089: removed

My confusion stemmed from thinking of the Postfix queue ID as the message ID. THIS IS WRONG. The message ID does not change. The queue ID changes if the message goes through the queue again. And, the way we have things set up, it goes through the queue twice: once when received, then again when SpamAssassin is done with it.

(Incidentally, I had wondered why SpamAssassin did not include the Postfix ID. This makes perfect sense when you realize it's a queue ID, and SA is not part of the Postfix queue.)

The other thing that makes this difficult is that the entries for a particular message are:

• spread over many lines
• only one of which will have the (unchanging) message ID
• not necessarily adjacent

Thus, the process for tracking down what's happened to a particular mail goes like this:

Look for the bit you have (who the message is from, let's say):

$ grep pepperoni@pepperoni.pizza /var/log/maillog
Apr  9 13:25:13 liddy postfix/qmgr[995]: 4DC3914C086: from=<pepperoni@pepperoni.pizza>, size=2019, nrcpt=1 (queue active)
Apr  9 13:25:13 liddy postfix/pickup[11886]: 85E1F14C089: uid=99 from=<pepperoni@pepperoni.pizza>
Apr  9 13:25:13 liddy postfix/qmgr[995]: 85E1F14C089: from=<pepperoni@pepperoni.pizza>, size=2323, nrcpt=1 (queue active)

Note the two queue IDs and search for those:

$ grep -E '85E1F14C089|4DC3914C086' /var/log/maillog.1
Apr  9 13:25:13 liddy postfix/smtpd[12203]: 4DC3914C086: client=mail.example.com[192.168.0.2]
Apr  9 13:25:13 liddy postfix/cleanup[12206]: 4DC3914C086: message-id=<deadbeef@example.com>
Apr  9 13:25:13 liddy postfix/qmgr[995]: 4DC3914C086: from=<pepperoni@pepperoni.pizza>, size=2019, nrcpt=1 (queue active)
Apr  9 13:25:13 liddy postfix/pickup[11886]: 85E1F14C089: uid=99 from=<pepperoni@pepperoni.pizza>
Apr  9 13:25:13 liddy postfix/cleanup[12206]: 85E1F14C089: message-id=<deadbeef@example.com>
Apr  9 13:25:13 liddy postfix/pipe[12207]: 4DC3914C086: to=<otheruser@club.sandwich>, orig_to=<ilikesandwiches@example.org>, relay=spamassassin, delay=0.25, delays=0.05/0/0/0.2, dsn=2.0.0, status=sent (delivered via spamassassin service)
Apr  9 13:25:13 liddy postfix/qmgr[995]: 4DC3914C086: removed
Apr  9 13:25:13 liddy postfix/qmgr[995]: 85E1F14C089: from=<pepperoni@pepperoni.pizza>, size=2323, nrcpt=1 (queue active)
Apr  9 13:25:43 liddy postfix/smtp[12212]: 85E1F14C089: to=<otheruser@club.sandwich>, relay=mail-relay.isp.tld[10.0.0.1]:25, delay=30, delays=0.01/0.01/30/0.35, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 92585180F0)
Apr  9 13:25:43 liddy postfix/qmgr[995]: 85E1F14C089: removed

Note the message ID and add it to the mix to get what SpamAssassin thought of it:

$ grep -E '85E1F14C089|4DC3914C086|deadbeef@example.com' /var/log/maillog.1
Apr  9 13:25:13 liddy postfix/smtpd[12203]: 4DC3914C086: client=mail.example.com[209.85.160.41]
Apr  9 13:25:13 liddy postfix/cleanup[12206]: 4DC3914C086: message-id=<deadbeef@example.com>
Apr  9 13:25:13 liddy postfix/qmgr[995]: 4DC3914C086: from=<pepperoni@pepperoni.pizza>, size=2019, nrcpt=1 (queue active)
Apr  9 13:25:13 liddy spamd[5110]: spamd: processing message <deadbeef@example.com> for nobody:99
Apr  9 13:25:13 liddy spamd[5110]: spamd: result: . 0 - scantime=0.2,size=1981,user=nobody,uid=99,required_score=5.0,rhost=localhost.localdomain,raddr=127.0.0.1,rport=42925,mid=<deadbeef@example.com>,autolearn=failed
Apr  9 13:25:13 liddy postfix/pickup[11886]: 85E1F14C089: uid=99 from=<pepperoni@pepperoni.pizza>
Apr  9 13:25:13 liddy postfix/cleanup[12206]: 85E1F14C089: message-id=<deadbeef@example.com>
Apr  9 13:25:13 liddy postfix/pipe[12207]: 4DC3914C086: to=<otheruser@club.sandwich>, orig_to=<ilikesandwiches@example.org>, relay=spamassassin, delay=0.25, delays=0.05/0/0/0.2, dsn=2.0.0, status=sent (delivered via spamassassin service)
Apr  9 13:25:13 liddy postfix/qmgr[995]: 4DC3914C086: removed
Apr  9 13:25:13 liddy postfix/qmgr[995]: 85E1F14C089: from=<pepperoni@pepperoni.pizza>, size=2323, nrcpt=1 (queue active)
Apr  9 13:25:43 liddy postfix/smtp[12212]: 85E1F14C089: to=<otheruser@club.sandwich>, relay=mail-relay.isp.tld[137.82.224.74]:25, delay=30, delays=0.01/0.01/30/0.35, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 92585180F0)
Apr  9 13:25:43 liddy postfix/qmgr[995]: 85E1F14C089: removed

And now you know...the rest of the story.

Trying to figure out how to add a bunch (well, 6) of LDAP user accounts. So far:

• ldapuseradd: neat; wish there was a dry-run mode; wish the hooks supported arbitrary scripts

• Python: neat; good to learn Python; have to avoid going down the rabbit hole of classes (Python made OOP clear to me in a way it hasn't before, and now everything looks like a nail)

• phpLDAPadmin: arghh; nooooo; can't script

Realistically this won't happen very often, so perhaps I should just go ahead and use the damn browser to do this. But it kinda hurts me a little inside when I do.

Just got off the phone w/a Sun rep who called up to see how I was doing, did I need any coasters, etc. I took the opportunity to put a bug in his ear about Solaris.

If Oracle removes the entitlement to run Solaris on non-Sun hardware, then what the hell do I have to play with? I've got a bunch of Sun hardware, but only one machine running Solaris -- and that's in production, holding home directories on ZFS; I'm not playing with that.

OpenSolaris folks are asking for answers and not getting any. And saying "Go run OpenSolaris" ignores the problem of figuring out what's in Solaris proper, what's going to be there RSN, and what's two or more releases out.

If Solaris disappears, then I'm not going to figure out how it's better; that's just how:

• my brain (I teach myself)
• my budget (Dell hardware irritates me but it's easily half the price)
• and my career (Open Source/Free Software FTW)

all work.

I like Solaris for precisely two things: ZFS and DTrace. Solaris has more, I know, but those are the things that matter to me. In all other respects, for me and my situation, Linux or the BSDs are good enough or better. And oh: FreeBSD has DTrace; DragonFly BSD has HAMMER; Linux has *@#%$)%! packaging.

No good ending for this, so we'll just call it quits.

Six books from O'Reilly on Windows Server 2003 (Cookbook, Security Cookbook, In A Nutshell, Netowrk Administration, Securing, and Learning) and there was ONE mention of SNMP in the indexes. What the hell?

Wow: my wife just bought me a ticket to Hoppapalooza. I am so lucky.

Been busy lately:

• 3 new workstations with OpenSuSE. Can't figure out the autoinstall, so it's checklist time, baby.

• Software upgrade for a fairly important server + 3 slave nodes. Natch, after rebooting one of the ILOMs for the servers just...went away. Can't ping it from the network. Works fine with an interactive ilom shell from Linux. Sometimes I really hate Dell software.

• Got a call from the reseller for a major hardware vendor who just got taken over by a major database vendor; said db vendor has just turned off educational discounts we'd spent THREE MONTHS negotiating/waiting to have approved. I am unimpressed. Strongly tempted to call up random hardware vendors and throw money at them 'til they give us stuff.

• Finally got leak detection working in the server room. Stupidly long time, it took.

• Working on a "Lessons Learned" presentation for LISA that'll include mention of the leak detection (among other things). Not sure how it'll be received, but I figure it's their job to tell me it sucks, not mine.

• New term coming, so about six new people coming. But at least I know about them in advance.

• And this...and this...just amuse me. (Warning: Flash eats babies and sells them to Chinese hackers.)

• Taxes.

But hey! Turns out we live in a constitutional democracy after all. There was some debate about this at 24 Sussex Drive, I understand. Score one for the good guys.

Michael W. Lucas, of Absolute FreeBSD fame (among many others), has a book coming out on Network Flow Analysis. Sweet!

/me hurries off to pre-order...