FinWX:n virtualisointiympäristön ja levyjärjestelmän päivitystyö ohi

[J.Jäntti]

FinWX:n historian pisin ja hankalin päivitystyö on saatu periaatteessa päätökseen. Kun on hereillä 32 tuntia putkeen (töissä oleminen mukaan lukien, päivityksen valmistelut ja itse päivitystyö), se verottaa loppupäästä kovemmin.

TL;DR:

ESXi:n päivitys meni ykkösellä läpi, levypakka ei. Mokasin asioita ja pakan vanhin levy kaatoi taustalla levyjärjestelmän, lopulta tuhoten RAID-ohjaimen toisesta koneesta ja vei vielä korvaavan koneen Kernel Paniciin ennen kuin jäi kiinni.
Ongelmat venyttivät huoltotyön 13-tuntiseksi maratoniksi. Olin hereillä yhteensä 32 tuntia putkeen tämän takia. Ei hyvää päivää näitä minun harrastuksiani... 

Tämä on tekninen raportti nimeltään


eli kun mikään ei mennyt levypakassa, kuin Strömsössä.

FinWX:n foorumi asetettiin huoltotilaan lauantaina kello 00:00, jonka jälkeen kaikki virtuaalikoneet ajettiin hallitusti alas ja ESXi Server asetettiin niin ikään huoltotilaan. Päivityspaketit menivät ESXi:lle vauhdikkaasti ja ilman minkäänlaisia ongelmia. ESXi nousi uusien päivitysten kanssa ylös kello 00:15 mutta pidettiin huoltotilassa ja koska seuraavana vuorossa oli levyjärjestelmä, joka vielä siinä vaiheessa oli näytti toimivan normaalisti...

Päivitys versioon 9.3.0.2 (1771) oli muutaman minuutin operaatio, eikä vaatinut ylläpidollisesti minkäänlaisia toimia. Järjestelmä näytti toimivan normaalisti vielä version 10.2.0.2 (1814):n kanssa mutta heti kun irrotin ESXi:n huoltotilasta ja käynnistin virtuaalikoneet, alkoivat ongelmat. Yhtäkkiä levypakan prosessorikuorma nousi käytännössä tappiin, serveri ei enää HTTP:n yli vastannut mitään ja SSH:n yli vastaukset tulivat ensin noin 30 sekunnin viiveellä ja lopulta ei enää sieltäkään. Serverin monitorilla juoksi "Unrecovable CRC/Parity Error"-ilmoituksia jatkuvalla syötöllä. ESXi näki tilanteen sellaisena, että yhteys levyjärjestelmään menetettiin äkillisesti. Sain konsolin kautta koneen käynnistettyä uudelleen mutta prosesseista osa oli niin jumissa, ettei sulautettu käyttöjärjestelmä niitä saanut sammuksiin, vaan kone piti pakolla ajaa virtanapista kyykkyyn. Kone palautui näennäisesti toimintakykyiseksi käynnistyttyään, muttei suostunut kertomaan lokitiedoissa lainkaan mikä nuo error-ilmoitukset oli aiheuttanut. Myöskin ZFS-tiedostojärjestelmän mielestä kaikki oli kunnossa, eikä syyllistä löytynyt mistään. Ongelmista kieli kuitenkin ESXi:n loki, joka sanoi seuraavaa:

Warning:
Frequent PowerOn Reset Unit Attentions are occurring on path vmhba37:C0:T0:L0. This might indicate a storage problem.
Affected device: t10.FreeBSD_iSCSI_DISK______NFSN00AZWRF80H__________________. 
Affected datastores: datastore-nas-raidz1

Ainoa vähäinen vinkki oli se, että virheet levyjärjestelmän konsolissa keskittyivät pääosin tiettyyn Serial-ATA-kanavaan, mutta päättelin häiriön johtuneen ohjelmaversiosta itsestään, joten päätin palauttaa sulautetun käyttöjärjestelmän takaisin lähtötilanteeseensa kello 02:15.

Koska ns. Downgrade-mahdollisuutta ei ollut, jouduin asentamaan koko sulautetun käyttöjärjestelmän uudelleen koneeseen. Tässä kohtaa tajusin mokanneeni jo alkuvaiheessa, kun huomasin että minulta puuttuu ohjelman asetustiedosto, siitä yksinkertaisesta syystä etten ollut sitä missään vaiheessa tajunnut edes ottaa (mikä on ylläpidon yksi kulmakivistä). Tämä tarkoitti sitä että jouduin käsin asettamaan kaikki asetukset uudelleen paikalleen ja nehän luonnollisesti muuttuivat iSCSI-puolella aivan toisen näköisiksi ESXi:n näkövinkkelistä. Ensimmäinen sydänkohtauksen oire meinasi olla lähellä kun yritin ZFS-levyjä esitellä levyjärjestelmälle uudelleen. On-disk Import-funktio luki levyjä pari sekuntia ja sitten totesi "ERROR: No pool found. Try to force-synchronize". Sydän kylmänä suoritin synkronoinnin uudelleen. Epäonnistuminen olisi tietänyt FinWX:n serverin ja sivuston täystuhoa, sekä sääasemaserverin, FinWX:n uuden serverin ja peliserverin katoamista bittiavaruuteen. Tällä kertaa levyt ilmestyivät. Oli pakko käydä parvekkeella hetken aikaa haukkaamassa happea ennen kuin palasi tappelemaan tekniikan kanssa.

Koska levyt piti esitellä uudelleen, levypakan tunniste muuttui. Tämä tarkoitti sitä, että ESXi tulkitsi levyn sisällön tilannevedokseksi (snapshot) eikä suinkaan viralliseksi levyksi jolloin se ei pysy näytillä, vaan pitää esittää ESXi:lle uudelleen kun ESXi käynnistetään mistä tahansa syystä uudelleen. Näin ollen ESXi:lle jouduttiin pakkosyöttämään tuo uusi tunniste, mikä tarkoitti sitä että virtuaalikoneet lakkasivat olemasta "natiiveja" kyseiselle levyjärjestelmälle ja niidenkin tiedot piti muuttaa myös samalla kertaa. Vanha versio näytti stabiililta, kunnes käskin ESXi:n purkamaan huomaamani iänikuisen vanhan virtuaalikoneen tilannevedoksen pois. Järjestelmä levisi välittömästi sen jälkeen kun vedostiedosto oli purettu ja SSD-välimuistilevyltä lähdettiin purattamaan dataa hitaammille kiekoille. Yllä olevaa PowerOn Reset Unit Attention-herjaa pukkasi ESXi:llä myös jatkuvasti, mitä pidin ensin vain uudemman version tuomana ominaisuutena, kunnes levypakan konsolin ruutu alkoi täyttymään jälleen Unrecovable CRC/Parity Error-ilmoituksista. Levyjärjestelmä lakkasi vastaamasta HTTP:llä ja SSH:lla ja ESXi ilmoitti levypakalle "APD":tä (All Paths Down, kaikki liikenne ESXi:n ja levypakan välillä poikki). Tässä vaiheessa kello oli jo 04:20 ja olin ollut ylhäällä putkeen lähes 23 ja puoli tuntia. Hermot alkoivat kiristymään.

Sain komennettua poikkeuksellisesti levypakan sammuttamaan itsensä ja käynnistymään uudelleen. Mielestäni bootin alkuvaiheesta puuttui jotain mutten väsymyksestäni johtuen pystynyt päättelemään mikä oli kyseessä ennen kuin sulautettu käyttöjärjestelmä alkoi paukuttamaan ruudulle "Main root mount waiting for Intel-GRAID" ja tätä tuli ruudun täydeltä noin 30 sekuntia jonka jälkeen järjestelmä teki ns. fallbackin ja nosti pakan ylös raaoilla AHCI-kanavamapeilla ja itserakentamallansa RAID-arraylla. Sillä ei päästy pitkälle, sillä ESXi ei nähnyt levypakkaa lainkaan ja ZFS totesi koko arrayn olevan UNAVAILABLE-tilassa ja että mitään siihen kuuluvaa levyä ei ollut olemassakaan. Katselin kulmakarvat katossa tätä näytelmää ja komensin sitten koko roskan boottaamaan itsensä uudelleen. Mikään ei iske pelottavammin väsyneeseen mieleen kuin nähdä alasajovaiheessa ilmoituksia, joissa lukee joko "Periph destroyed" ja "Array destroyed" ennen kuin kone ajaa itsensä alas.

Keskityin nyt Intel-GRAID-ilmoitukseen koska sitä ei ollut aiemmin näkynyt. Boottasin koneen ja huomasin että Intelin ICH-piiriin kuuluva RAID-palikka ei edes ladannut itseään eikä BIOS:n jälkeen mikään muukaan ns. On-board BIOS käynnistynyt ja BIOS oli ainoa joka listasi asennetut kiekot. Kummastelin sitä hetken ja yritin BIOS-asetuksia vaihtamalla saada tilanteen normalisoitua mutta mitään muutosta ei syntynyt. Annoin koneen bootata itsensä ja katsoin kun kone teki samoin kuin teki viimeksikin. Tajusin siinä vaiheessa, että koneen RAID-piiri on romuttunut. En ymmärrä miten ICH-piiri toimi muulta osin mutta RAID-toimintoa sieltä ei enää saatu. Kello oli tuossa vaiheessa 05:10. Olin ollut 24h putkeen hereillä. Tiesin että koko projekti jämähti nyt niille tolpilleen ja mikään serveri ei täällä ole nousemassa ylös. Menin hakemaan lisää kahvia ja painuin parvekkeelle istumaan viilentämään ylikierroksilla käyvää päätäni.

Ainoa ratkaisu oli "kannibalisoida" yksi samoilla spekseillä varustettu, vierailijoille tarkoitettu pelikoneeni. Vaihdoin räjähtäneestä purkista kiintolevyt toimivan koneen koppaan, varmistin että levyt ovat tasantarkkaan niissä samoissa Serial-ATA-kanavissa kuin ne olivat räjähtäneessä koneessa, siirsin sulautetun käyttöjärjestelmän sisältävän USB-tikun toimivaan koneeseen, raahasin sen paikoilleen, kaapelit kiinni, kone päälle ja BIOS-asetukset vanhan koneen kanssa identtisiksi. Sulautettu käyttöjärjestelmä oli hetken aikaa kummissaan kun sen omaksumat speksit eivät ihan 100% olleet samat. Sain säätää pari asetusta uusiksi mutta lopputulos oli se, että se toimi. ZFS ilmoitti konfiguraatiomuutoksesta, jonka kuittasin pois koska se oli odotettavissa. ESXi näki levypakan ja annoin virtuaalikoneiden päästä takaisin kartalle tilanteesta johon ne jäivät kun RAID-piiri hajosi. Kokonaisuudessaan tilanne näytti hyvältä, sillä virheitä ei tullut levypakan puolella. ESXi huuteli edelleen "PowerOn Reset Unit Attention"-herjoja, mikä kummastutti minua, sillä mikään ei viitannut suoraan vikaan. Oletin edelleen kyseessä olevan viimeisimmän ESXi-laastarin aikaansaannosta. Koska testi oli kaksi tuntia jauhanut ja serveri näytti rauhoittuvan, ajoin virtuaalikoneet alas ja päivitin levypakan viimeisimpään 9.3-versioon kello 11:35. Kun järjestelmä oli noussut ylös, ajattelin että vetäistäänpä levypakan ketjusta oikein kunnolla ja käskin ESXi:n nostaa kaikki virtuaalikoneet kerralla käyntiin. Käsky kävi ja koneet lähtivät ylös. Saman tien alkoi ESXi esittämään latenssiherjoja sellaisilla mikrosekuntilukemilla, jotka ennakoivat että kohta käy huonosti - ja niin kävikin: Samalla sekunnilla kun ESXi ilmoitti APD:stä, konsoli täyttyi jälleen kerran tutuista erroreista. Totesin tilanteen ja ajoin levypakan alas kello 11:42.

Aloin olemaan tässä kohtaa varma että emolevyn rautavika se ei ole, vaan joku levyistä on nyt heikoissa kantimissa. ahcich2:ssa oleva levy oli syytettyjen penkillä kun herjat alkoivat vilistä joten kirjasin sen paperille ja pakotin pakan nurin. Kun levypakka saatiin takaisin näkyviin, ajoin pakkosyötöllä Offline-SMART-diagnostiikan joka levylle. ahcich2:ssa oleva levy ilmoitti siirrelleensä sektoreita levyllä varasektorien varaan, mikä viittaa heikentyvään levyn kuntoon. Sen lisäksi levy kävi oudon kuumana, ollen 51°C (muut olivat 36°C ja 38°C). Komensin tuon levyn Offline-tilaan ZFS:stä ettei järjestelmä käyttäisi sitä enää. Komento hyväksyttiin ja levy irrotettiin loogisesti. Virtuaalikoneiden jatkaessa ylösnostoaan huomasin sivusilmällä, että konsolissa juoksi jotain tekstiä. Ehdin lukemaan jotain Kernel Panicista ennen kuin ruutu pimeni ja levypakka aloitti boottaamaan itseään. Sammutin levypakan boottivaiheessa, poistin tuon huonosti käyttäytyneen levyn koneesta fyysisesti ja käynnistin pakan uudelleen. Järjestelmän noustua ylös järjestelmä totesi ahcich2:ssa olevan levyn kadonneeksi ja pudotti pakan statuksen DEGRADED-tilaan. ESXi havaitsi pakan palanneen ja alkoi jälleen keskustelemaan sen kanssa. Jotain oli kuitenkin jäänyt hetkellisesti ESXi:llä hampaankoloon sillä yhtäkkiä ESXi ilmoitti yhteyden levypakkaan taas kadonneeksi. Levypakka kuitenkin vastasi ja ilmoitti lokitiedoissa ESXi:n hakanneen noin 30 kertaa TASK_ABORT-signaalia levypakalle ja resetoineensa iSCSI-väylän sen jälkeen. Yhteys palasi tuon jälkeen eikä ole kadonnut. Myös PowerOn Reset Unit Attention-herjat olivat loppuneet levyn irrotuksen jälkeen, joten syyllinen löytyi ja eliminoitiin. Viimeiset testit suoritettiin levypakalle, kiusaten sitä erinäisillä virtuaalikoneiden tekemisillä, yrittäen saada pakkaa limboon, mutta näin ei käynyt; Levypakka hoiti virkaansa kuten sen kuuluikin.

FinWX:n palvelut nousivat tuotantoon kello 13:00. Huoltotyö päättyi viisi tuntia asetetusta takarajasta myöhässä.
Korvaava levy on tilattu ja sen odotetaan saapuvan seuraavalla viikolla, jolloin luvassa on uusi huoltokatko.

Vuorokausirytmin apinanraivoinen korjaus on puolestaan menossa, muutoin maanantaina odottaa sen tasoinen perikato että ärrälle morjens.