Category Archives: sysadmin

Paving the road from CRITICAL to OK

Imagine you have an issue on your mail server. It’s an intricate issue, one of those whose origin may be difficult to track because it lies on the lowest levels of the system: mail server runs on a legacy operating system inside a virtual machine on top a modern host that attaches disk images from a clustered storage system, connected into a fast network and receiving user requests via load balanced tunnels, etc.

There are so many parts running this setup that figuring out what happened could be a lot of effort, so the first thing that comes to your mind are the metrics collected by Munin (aha! let’s find some correlation of events in those graphs). So, you open the Munin web pages and you discover that it’s been 3 days since graphs were last updated. You think that maybe the state files were updated and you just need to rebuild the graphs… Bad luck, again.

How could this happen and nobody noticed? You think that we need to add some Nagios checks for the Munin lock files, so you get a warning or critical alert if it’s been too long since last update, right? Then you discover that the check is already there and it’s been moaning every single one of those 3 days that Munin wasn’t being updated. Well, it happens that Munin is not a core service, it’s only useful once in a while, though it can be very frustrating not having it when you actually need it. Thus, nobody payed attention to that alert because nobody needed Munin at that time and there were other alerts more pressing. So, what will happen next time?

Okay, you promise that next time you’ll pay more attention to those critical alerts and see that Munin needs an intervention. Are you happy with that? I’m not. I believe that errors caused by humans raise defects on the underlying system being operated. Also, I believe that repetitive work is a bad approach to solve any issue. Automation makes IT better.

In this particular case, Munin fails to remove its locks sometimes for whatever reason (it may well be that there’s something caused by our configuration, but it’s not worth the trouble to debug it because it only happens a few times a year). When it happens though, Nagios checks send alerts and the person on call should connect to the Munin server and just remove the locks. That’s just it, remove the locks. Therefore, I added an event handler to those Nagios checks that will remove the lock next time is gets too old. The critical alert will be triggered anyway and that’s good because it’s a critical event that should be recorded, but the system will take care of that immediately and very soon it will be OK again.

Now I’m wondering how many of our critical alerts could be automated like this. I’m sure that not all of them will be that easy to automate, but what if most of them are? Well, I won’t start adding random event handlers everywhere. I’ll wait for the next issue that raises an automation opportunity because I’m a huge fan of small steps. I hope you’ll do the same.

Please mount Volume or label a new one?

A Monday morning we found several messages like this from Bacula:

09-Sep 18:27 Tape-A JobId 15196: Please mount Volume "A0000038" or label a new one for:
    Job:          sites.2012-09-08_01.50.03_40
    Storage:      "LTO-4" (/dev/nst0)
    Pool:         Default
    Media type:   LTO-4

That was Bacula complaining about the wrong volume on the drive. However, after examining the status of storage the weird thing was that the tape with barcode “A0000038” was actually mounted on the drive, it was purged and had 0 bytes used… WTF?

We started suspecting our tape rotation algorithm was not taking into account that maybe purged tapes were not used if data retention hadn’t expired, but Automatic Volume Recycling says otherwise and some tests on other purged tapes with expired data retention failed too.

Several days of searching similar issues later, it seemed clear that there was something wrong only with some purged tapes from the media catalog. So i came up with a quick test for each one of our purged tapes in order to make sure that they were labeled correctly. First, i loaded “A0000038” and read its label:

# mtx -f /dev/sg4 load 22
Loading media from Storage Element 22 into drive 0...done
# dd if=/dev/nst0 bs=65000 count=1 | od -a | head
0+0 records in
0+0 records out
0 bytes (0 B) copied, 3.81024 s, 0.0 kB/s
0000000

You can see that it failed to find any Bacula label, so next i tried the same test with another tape in full state that had been used the day before:

# mtx -f /dev/sg4 load 16
Loading media from Storage Element 16 into drive 0...done
# dd if=/dev/nst0 bs=65000 count=1 | od -a | head
0+1 records in
0+1 records out
64512 bytes (65 kB) copied, 3.73563 s, 17.3 kB/s
0000000   G   ;   =   < nul nul nul   D nul nul nul nul   B   B   0   2
0000020 nul nul stx  gs   L etx   O sub del del del   ~ nul nul nul nul
0000040 nul nul nul 240   B   a   c   u   l   a       1   .   0       i
0000060   m   m   o   r   t   a   l  nl nul nul nul nul  vt nul eot dc3
0000100   1   8   O  si  ff nul eot dc3   J   +   W stx   p nul nul nul
0000120 nul nul nul nul nul nul nul nul nul nul nul nul nul   A   0   0
0000140   0   0   0   0   6 nul nul   D   e   f   a   u   l   t nul   B
0000160   a   c   k   u   p nul   L   T   O   -   4 nul   v   m   -   h
0000200   o   s   t   -   4 nul   T   a   p   e   -   A nul   V   e   r
0000220   .       5   .   0   .   1       2   4       F   e   b   r   u

(Note that device /dev/nst0 has a minimum block size of 64512 bytes, otherwise dd would raise a Cannot allocate memory error.)

This time the Bacula label was found on the tape (the Bacula 1.0 immortal string is a clue), so we were now on the right track. Then i reviewed our wiki for the tape change procedure and there was an optional step in the tape purging section explaining how to blank a tape from another Bacula director before labeling it for this one. Therefore, it seemed that someone had been blanking the tapes after purging them and Bacula didn’t know what to make with them even though they had the right barcodes.

The fix was quick: i tested every purged tape to make a list of the blanked ones, then deleted them from the catalog and labeled them back from the bconsole:

* delete volume="A0000038"
* label barcodes slots=22 pool=Default

Bacula is happy again, and we are too! 🙂

etckeeper en mode silenciós

Hi ha eines que quan les descobreixes et semblen genials. Aquest és el cas de etckeeper, una eina que permet mantenir el directori /etc sota un sistema de control de versions (VCS) com ara git, mercurial, bzr o darcs. Un dels seus avantatges principals és que guarda una còpia abans i després d’instal·lar paquets al sistema, de forma que és molt fàcil de veure els canvis que es produeixen a les configuracions. Un altre és que s’acostuma a executar diàriament una còpia dels canvis mitjançant un crontab i si hi ha canvis es mostren en el correu corresponent que envia el dimoni cron. D’aquesta manera si faig canvis al /etc i no els he desat, el cron s’encarregarà de fer-ho un cop al dia.

Però aquest darrer avantatge es pot convertir en un greu inconvenient si instal·leu etckeeper en un clúster relativament gran o si gestioneu molts servidors. Idealment, per cada canvi que es faci al /etc caldria executar després «etckeeper commit …» per tal de guardar els canvis al VCS. Per exemple,  després de canviar la contrasenya d’un usuari o d’afegir-ne un de nou. Però si us oblideu de fer-ho, l’endemà potser us trobeu més d’un centenar de correus amb els canvis de cada servidor.

Doncs bé, una opció és acceptar que només us interessa rebre missatges en cas que es produeixi un error i els canvis diaris que es facin silenciosament. La primera idea que se’ns podria ocórrer és canviar el crontab del etckeeper perquè enviés la sortida estàndard a /dev/null però resulta que «bzr commit» (per defecte, etckeeper a ubuntu tria bzr com a VCS) treu el seu informe per l’error estàndard! Com que redirigir també l’error estàndard a /dev/null sempre és una mala idea (si es produís un error no us n’assabentaríeu), cal buscar una altra estratègia. Afortunadament és possible canviar les opcions dels diferents VCS a la configuració i per al cas de bzr només cal posar això al fitxer /etc/etckeeper/etckeeper.conf:

BZR_COMMIT_OPTIONS="-q"

Amb el que cada cop estic més a prop de tenir menys correu a la bústia d’entrada 🙂

Reduir els correus de Bacula

El Bacula és un sistema de gestió de backups professional en programari lliure (també es pot contractar suport empresarial, si cal). En la configuració predeterminada és costum enviar un correu per cada treball que indiqui si ha finalitzat correctament o no. Però en un entorn amb una pila de servidors i diversos treballs per servidor, això implica rebre diàriament molts correus que habitualment indiquen que tot ha anat bé. En el meu cas, són entre 60-70 correus diaris.

Afortunadament, si hom disposa d’un sistema de monitoratge compatible amb Nagios, pot utilitzar un connector que examina els logs del bacula director per veure si s’ha produït algun error. Per tant, ja no cal seguir rebent aquest allau diari de correus que indiquen que els treballs han acabat bé. Per fer-ho només cal que canvieu la configuració dels Messages anomenats Standard al fitxer /etc/bacula/bacula-dir.conf i on posava «mail» hi poseu «mail on error»:

Messages {
  Name = Standard
  mailcommand = "/usr/lib/bacula/bsmtp -h localhost -f \"\(Bacula\) \<%r\>\" -s \"Bacula: %t %e of %c %l\" %r"
  operatorcommand = "/usr/lib/bacula/bsmtp -h localhost -f \"\(Bacula\) \<%r\>\" -s \"Bacula: Intervention needed for %j\" %r"
  mail on error = bacula@example.com = all, !skipped
  operator = bacula@example.com = mount
  console = all, !skipped, !saved
  append = "/var/lib/bacula/log" = all, !skipped
  catalog = all
}

Amb aquest canvi, tots els treballs que utilitzin els missatges estàndard passaran a enviar correus només en cas que es produeixi algun error. Però potser us interessa que els treballs de recuperació sí que notifiquin si han acabat bé i així podeu evitar d’estar pendents dels logs, oi? Doncs és ben fàcil també: només cal crear un nou tipus de missatge pels treballs de recuperació que tingui «mail» enlloc del «mail on error» i indicar-ho a la secció corresponent:

Job {
  Name = "RestoreFiles"
  Type = Restore
  Client = bacula-fd
  Storage = Tape
  FileSet = "Full Set"
  Pool = Default
  Messages = Restore
  Where = /tmp/bacula-restores
}

Messages {
  Name = Restore
  mailcommand = "/usr/lib/bacula/bsmtp -h localhost -f \"\(Bacula\) \<%r\>\" -s \"Bacula: %t %e of %c %l\" %r"
  operatorcommand = "/usr/lib/bacula/bsmtp -h localhost -f \"\(Bacula\) \<%r\>\" -s \"Bacula: Intervention needed for %j\" %r"
  mail = bacula@example.com = all, !skipped
  operator = bacula@example.com = mount
  console = all, !skipped, !saved
  append = "/var/lib/bacula/log" = all, !skipped
  catalog = all
}

Es tracta d’un petit canvi que pot augmentar significativament la productivitat d’un equip de sysadmins amb una pila de servidors dels quals es fan còpies de seguretat cada dia.

Cyrus said: 554 5.6.0 Message contains NUL characters

Feia unes quantes setmanes que rebia un munt de correus de backscatter a postmaster que em portaven de corcoll. Els missatges indicaven que el nostre MDA (Cyrus IMAP 2.2) no acceptava els correus que havien arribat al MTA intern (Postfix 2.5.1) perquè contenien caràcters nuls:

<xxxxxxxx@[x.x.x.x]>: host x.x.x.x[/var/run/cyrus/socket/lmtp]
    said: 554 5.6.0 Message contains NUL characters (in reply
    to end of DATA command)

Primer vaig mirar si la versió de Sieve que ve amb Cyrus suporta les extensions per filtrar basant-se en el contingut del cos però no hi va haver sort (amb Cyrus 2.4 ja està suportat però a la 2.2 no). Així que buscant buscant vaig trobar un fil molt interessant de la discussió original l’any 2005, on s’anaven passant la culpa de Postfix a Cyrus i a l’inrevés, com en un partit de tennis, mentre invocaven la màxima aquella de «be liberal in what you accept and strict in what you send». Tot i que en principi en Wietse Venema va dir que no podia dedicar temps a implementar el filtre a Postfix, finalment el va poder incloure a la versió 2.3 i ara la solució és prou senzilla:

message_strip_characters = \0

Amb aquest petit canvi he deixat de rebre diàriament centenars de notificacions de postmaster d’aquest tipus que em feien perdre un munt de temps.

2012 serà el meu any d’automatització

Després d’una temporada aprenent i muntant eines com Puppet i FAI a la feina, veient el panorama que dibuixa Ubuntu amb l’Orchestra, el Juju i el nou projecte MaaS, segurament el propòsit més important que m’he fet per aquest 2012 és el d’automatitzar tot el que pugui per evitar perdre temps en tasques repetitives i mecàniques, tal com apunta en Tom Limoncelli al seu llibre sobre gestió de temps per a administradors de sistemes.

En aquest sentit, un bon indicador de coses a automatitzar són els correus que rebo diàriament sobre els backups, els crons i les notificacions de postmaster. He decidit que com que no puc ignorar-los i mentre els segueixi rebent continuaré perdent molt de temps processant-los cada dia, el meu objectiu serà deixar-los de rebre; preferiblement perquè hauré pogut automatitzar algun procediment, simplificar alguna tasca o emmagatzemar alguna sortida, etc. Si per algun motiu no ho puc aconseguir, no em quedarà altre remei que delegar aquesta feina, que en el fons és una de les solucions que proposen tant en David Allen com en Tom Limoncelli.