Loggings
...BEEEP BEEEP BEEEEP BEEEP... L'allarme di prossimita' continua a strillare imperterrito mentre il missile a frammentazione passa meno di 300 Km di distanza, la sua traiettoria alterata dalla gravita' del gigante gassoso attorno alla quale la "HaiProvatoARiavviare?" sta orbitando.
Il missile esplodera' prima di raggiungere l'atmosfera del pianeta, tra un 25 minuti circa. Ma questo e' uno, ce ne sono altri due in arrivo, e qualche cosa mi dice che chiunque sia seduto sulla poltrona del Controllo Missili sull'incrociatore nemico in questo momento sta' aggiornando la traiettoria per tenere conto della forza di gravita' del pianeta.
Il computer mi informa che i due missili stanno correggendo la loro traiettoria, i razzi di guida sono degli sbuffi di gas, invisibili ad occhio nudo ma di un bel rosso brillante all'infrarosso contro i 2 Kelvin dello spazio circostante. I missili arrivano alla velocita' di crociera di 30.000 mt/s, con una accellerazione di 8g per la correzione di traiettoria... Il computer mi informa che il primo missile probabilmente passera' a meno di 20 Km di distanza. Troppo vicino.
Il cambiamento di orbita e' in corso da almeno 10 minuti, dovrebbe portarmi abbastanza vicino alla seconda luna del pianeta per confondere il radar del missile. L'incrociatore e' a 600000 Km di distanza quindi la correzione di rotta raggiungera' il computer del missile solo tra 2 secondi...
BEEEP BEEP BEEEEEEEEP ... Che capp..?? Un altro segnale compare sullo scanner, questo e' vicino pero'. Un po' troppo vicino. Cosa accidenti ci fa' a 20 Km di distanza?
BEEEP BEEEEP BEEEEP OCacchioOk, ok mi sveglio adesso... Porkatroika...
Brancico cercando il pager che sta' cercando di svegliare l'intero quartiere (riuscendoci benissimo) e fermo l'allarme mentre con l'altra mano cerco di trovare la luce. Trovo invece uno dei gatti che pero' non si illumina ma si limita a miagolare. Dopo essere riuscito ad accendere la luce guardo il pager... Poi penso che se mi infilo gli occhialo magari riesco pure a leggere cosa cazzo dice.
Allarm: disk space $machinename
Oh che bellezza. Le gioie di essere "on call".
Accendo il computer faccio login, o meglio ci provo dato che il risultato e' un 'access denied'. Qualche cosa mi fa pensare che il coglione che ha configurato questo coso NON HA messo /var come partizione separata. Come e' scritto chiaramente sulle "best practice" e come viene detto e ripetuto praticamente a tutti da me. Da almeno un anno e mezzo. Il risultato e' che qualche processo del cazzo ha riempito /var/log e quindi / e adesso non si riesce piu' a fare un login manco morto.
E' ora di provare la console. Dopo aver madonnato per un quarto d'ora per cercare quale delle millemila password "di default" e' stata usata, riesco a fare login e confermo i miei sospetti: /var/log e' 16 Gb su un disco da 20 Gb.
Trovo quasi subito il colpevole in un bel file "data_processing_debug.log" e lo zappo, liberando in un botto solo 7 Gb. Dopo un attimo il file ricomincia a crescere con la velocita' di un mostro alieno.
Hummm... Forse sono io, ma il contenuto di questo coso mi pare sull'inutile andante. Comunque sia, ho due scelte: o blocco quello che scrive su questo coso e lo faccio scrivere su qualche cosa d'altro (tipo, /dev/null) o l'intera macchina sara' di nuovo piena zeppa nel giro di... un'ora. Ok, che /dev/null sia.
Dopo un po' di smanettamenti sembra che tutto funzioni e niente venga piu' loggato. Scrivo il rapportino dettagliando la faccenda, con dettaglio anche delle ore spese e me ne torno a dormire. Ovviamente il giorno dopo arriva il programmatroto di turno (CL) a lamentarsi della cosa.
CL - Ma perche' il file di log e' stato cancellato? A noi serve il logging per il debugging.
Io - Prima di tutto, il debugging dovrebbe essere fatto sul sistema di test, non su quello di produzione, per seconda cosa, noi abbiamo due scelte: eliminiamo i file di log che crescono troppo e troppo rapidamente, o lasciamo l'intero sistema bloccato.
CL - Ma il file di log non blocca l'intero sistema.
Io - Lo blocca si, se riempie completamente la partizione di / che e' anche dove si trova tutto il resto. Root piena, significa niente spazio per scrivere i dati di niente, incluso il vostro database. Il database non puo' piu' scrivere, tutto il resto smette di funzionare.
Dopo aver spiegato la cosa per la novantaseiesima volta, riesco a mollare CL, ma a questo punto e' DB che si appropinqua.
DB - Che e' successo con il server di CL?
Io - E' successo che qualche coglione ha installato la macchina senza leggere la documentazione, quindi con partizionamento di default che mette praticamente tutto in /, e che qualche altro coglione ha fatto il "controllo qualita'" con la stessa accuratezza, cioe' nessuna. Con il risultato che tutti si aspettano. O meglio, tutti quelli che sono capaci di usare il cervello.
DB - E perche' non e' stato notato da chi fa la lettura dei log?
Io - E perche' non lo domandi a chi DOVREBBE fare la lettura dei log? Magari a quelli che AVREBBERO dovuto leggere i log negli ultimi... mah... 3 giorni?
DB - E come mai non appare nei grafici...
Io - Perche' lo stesso coglione che ha installato malamente la cosa non ha attaccato i grafici. Adesso hai finito di fare domande che hanno sempre la stessa risposta o vogliamo andare avanti ancora un po'?
DB - Sto solo cercando di capire come mai si e' verificato questo incidente...
Io - Questo non e' un incidente, e' il prodotto prevedibile di una amministrazione incompetente. Ed e' incompetente perche' le procedure che esistono non sono applicate. E non sono applicate perche' chi di dovere non controlla e non le fa applicare. Ed indovina chi dovrebbe essere quel "chi di dovere"?
DB - Adesso devo andare a parlare con il megacapo di questa faccenda, poi se ne riparla.
Yep... E' sempre "poi se ne riparla"...
Comunque sia, per il resto della giornata non si e' piu' visto.
Fast forward di circa 12 ore, quando il pager si e' rimesso a suonare sempre alle 2 del mattino. E si', e' sempre lo stesso stracazzo di file di log che cresce a dismisura. Ripeto l'operazione e ri-segno il tempo (di sonno) perso.
Il giorno dopo mi dirigo immediatamente al tavolo di DB.
DB - Non dirmelo... Di nuovo il server di CL.
Io - Ovviamente.
DB - Avrebbero dovuto sistemarlo...
Io - Ed ovviamente non lo hanno fatto. A questo punto domando io che cosa dobbiamo fare con questo arnese.
DB - Bhe', niente...
Io - "Niente" non e' una risposta accettabile. Se esiste un problema, ed in questo caso e' ovvio che esiste, tale problema deve essere affrontato e risolto.
DB - Tu che proponi?
Io - Fase uno: rimuovere il logging da quella applicazione.
DB - Non possiamo rimuovere il logging, lo usano per debuggare.
Io - Fase due: installare sistema di test dove debuggino.
DB - E chi la paga?
Io - Loro. Oppure sospendiamo il monitoring e se l'applicazione si incarta, e si incarta di sicuro, rimane incartata.
DB - No, questo e' inaccettabile.
Io - Ottimo. (metto il pager sul tavolo) Questo te lo tieni tu allora, perche' io stanotte non mi alzo.
Ne segui' una lunga e ponderosa discussione, che e' troppo lunga per essere riportata. In ogni caso, il mio punto di vista era ed e' tutt'ora che il monitoring deve coprire INCIDENTI, che sono avvenimenti imprevedibili ed inevitabili, mentre un PROBLEMA che e' prevedibile e EVITABILE deve essere trattato in maniera diversa. Agire sempre in "attivita' di emergenza", non dimostra ne' capacita' ne' efficienza. Tutto il contrario in effetti.
E se il problema e' il risultato di un piu' grosso problema di natura STRUTTURALE e ORGANIZZATIVA, deve essere risolto nello stesso modo.
DB - ...che intendi dire?
Io - Che abbiamo delle procedure, procedure che dovrebbero essere seguite perche' sono parte integrante di tutte quelle stracazzo di "certificazioni" che sono tanto care a tutti quanti, se le procedure non sono seguite non dovremmo stupirci del fatto che le cose non funzionano come ci aspettiamo.
DB - Hmmm..
Io - E perche' siano seguite dovrebbero esserci delle corrispondenti procedure amministrative che devono essere seguite. Per esempio, una di queste procedure specifica che quando un sistema viene installato, prima che diventi "produzione" deve essere verificato, questo non e' stato fatto sul sistema di CL, tuttavia il sistema e' andato in produzione. Perche'?
DB - E' che era una cosa urgente...
Io - E' SEMPRE una cosa URGENTE. Ma chissa' come mai, siamo sempre NOI che dobbiamo smazzarcela. Bene, adesso te la smazzi tu.
Da quel momento il file di log del server di CL e' rimasto symlinkato a /dev/null.
Davide
24/05/2018 13:53
