KVM i task blocked for more than 120 seconds – solved

Sprawę miałem opisać już jakiś czas temu i zapomniałem, a jest szansa, że komuś się przyda. Był sobie serwer, na którym działało trochę VPSów. Wszystkie KVM, wszystkie z systemem plików ext4 i obrazem dysku qcow2. Czyli standard. Sprzęt nie pierwszej młodości, ale działały względnie stabilnie. Poza jedną, w sumie najbardziej obciążoną, bo działał w niej jeden z serwerów Zabbixa, niespecjalnie obciążony w porównaniu z innymi, w których jednak żaden nie działał w KVM.

Tej jednej zdarzał się zaliczyć zwis, z komunikatami:

kernel: INFO: task XXX blocked for more than 120 seconds.kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Wymagany był reboot wirtualki. Dotyczyło to różnych tasków, a całość działa się losowo – potrafiło działać przez kilka tygodni, a potrafiło wywalić się co parę dni, co nie ułatwiało diagnostyki. Początkowo działo się to na tyle rzadko, że sprawa została zignorowana, ale w miarę wzrostu obciążenia maszyny fizycznej, problem się nasilał. Objaw był taki, że operacje wymagające zapisu na dysk nie wykonywały się (czyli monitoring zdychał). Zacząłem szukać przyczyn – pierwotnie podejrzenie padło na coś, co wykonuje się z crona, bo sporo procesów crona wisiało, ale przejrzenie skryptów pokazało, że niespecjalnie mogą one być przyczyną

Wyglądało, jakby momentami coś nie wyrabiało się dostępem do dysków w momentach większego obciążenia. Z tym, że znowu – widać było, że nie jest to deterministyczne. Ponieważ maszyny jak wspomniałem starawe, to podejrzenie padło na sprzęt – problemy z dostępem do dysków potrafią robić cuda. SMART pokazywał, że wszystko OK, ale sprawdzić nie zawadzi… Przeniesienie wirtualki na inną, mniej obciążoną maszynę fizyczną nie przyniosło rezultatów – wieszało się nadal, chociaż rzadziej.

Oczywiście wyłączenie komunikatu, które jest w nim wspomniane, nie rozwiązuje problemu. W międzyczasie trafiłem na opis rozwiązania problemu, czyli zmniejszenie vm.dirty_ratio oraz vm.dirty_backgroud_ratio. Tylko że… to nie pomogło. Nie pomogło także zwiększenie kernel.hung_task_timeout_secs początkowo do 180, potem do 300 sekund. Było trochę lepiej, ale problem nadal występował. Pół żartem, pół serio zacząłem się zastanawiać nad automatycznym rebootem po wystąpieniu problemu (zawsze to krótsza przerwa), ale to brzydkie obejście, nie rozwiązanie. Tym bardziej, że w miarę wzrostu obciążenia i VPSa, i maszyny fizycznej na której on działał, problem zaczął występować częściej – góra co parę dni. Paradoksalnie, dobrze się stało, bo i motywacja większa, i sprawdzanie efektu wprowadzonych zmian łatwiejsze.

Z braku opisów w sieci, pomocy znajomych adminów i innych pomysłów zacząłem sprawdzać po kolei wszystko. Od fsck systemu plików, przez nowsze wersje kernela, zarówno na maszynie fizycznej, jak i na wirtualce – a nuż coś poprawili. Bez rezultatu. Ostatecznie postanowiłem zmienić format dysku wirtualki z qcow2 na raw i… trafiony, zatopiony – wirtualka zaczęła działać stabilnie.

Dla pewności wróciłem jeszcze z raw z powrotem na qcow2, na wypadek, gdyby chodziło o jakieś błędy, których nie wykrywało narzędzie do sprawdzania qcow2, ale… problem natychmiast wrócił. Gwoli ścisłości: ww. tuning dotyczący parametrów kernela z serii vm.dirty został zachowany.

Monitoring w pracy

Nadzór w pracy istnieje od zawsze. Jakby nie było, jest to jedna z funkcji kadry kierowniczej. Zastanawiałem się ostatnio, jak to wygląda obecnie, co się zmieniło. O tym, że coraz więcej zakładów ma zamontowane kamery powszechnie wiadomo. Zresztą rejestratory video staniały i spowszedniały na tyle, że spora część znajomych ma je zamontowane w samochodach czy na rowerach. Opinie na ich temat w miejscach pracy są różne, część pracowników jest (była?) zdecydowanie niechętna, ale IMO tak naprawdę wszystko zależy, jak są wykorzystywane i umieszczone. Pracuję w miejscu, gdzie są kamery i raz mi osobiście jako pracownikowi się przydały.

Sprawa trywialna, coś z laptopem i dyskiem było. Kumpel przyniósł czyjegoś służbowego lapka, ja wyjąłem z niego dysk, podłączyłem do kieszeni, IIRC zrobiłem diagnostykę, wkręciłem dysk z powrotem, oddaję lapka. No i przychodzi kumpel, pokazuje zdjętą zaślepkę, pusto, i pyta „a gdzie dysk?”. Szukamy. Tak całkiem pewien, że go wsadziłem z powrotem to nie byłem, bo raczej odruchowo działałem, więc sprawdzam biurko, szuflady. Jak się tak rozglądam, to jestem coraz bardziej przekonany, że włożyłem z powrotem. Kumpel upiera się, że dostał ode mnie, otworzył i było pusto. Zgrzyt.

No to wzięliśmy nagranie z rejestratora. I widać jak wyjmuję, podłączam do kieszeni, wkładam z powrotem, przykręcam. Kumpel obraca lapka tak, jak jest na kamerze i pokazuje pustą dziurę po lewej. Patrzymy w monitor, wkręcam po prawej. WTF? Patrzymy na lapka i w śmiech. Ano tak, laptop był 17″ i miał dwa sloty na dysk, ale to zupełnie nie przyszło nam do głowy.

Tak czy inaczej, nagrania z kamer są dość dokładne (no dobrze, zależy od kamery i ustawień jeszcze), ale raczej trudno je analizować automatycznie. Forma strawna dla komputera to raczej osoba, timestamp, określenie miejsca. Oczywiście da się zrobić, bo pozycjonować można choćby smartfona (i aktywnie, przy pomocy aplikacji na smartfonie, i pasywnie, z wifi), no ale nie każdy pracownik w zakładzie musi mieć smartfona, włączonego, z wifi itd.

Niedawno dostałem namiar na stronę https://www.autoid.pl/ czyli dostawcy systemów do automatycznego… praktycznie wszystkiego – identyfikacji osób, przedmiotów, pojazdów itp. i dostałem odpowiedź na moje pytanie, jak można w sposób łatwo przetwarzalny komputerowo monitorować miejsce przebywania pracownika w firmie. Technologia opiera się na RDIF, które mogą służyć nie tylko do jako karty dostępu do drzwi (de facto standard w firmach, kto nie ma karty?), ale w wersji „dalekiego zasięgu” (do 12 m)  mogą być odczytywane bez przykładania do czytnika. Wygląda na prostsze i tańsze od smartfona u pracownika, prawda?

Producent podpowiada nawet sposoby umieszczenia – zaszycie w ubraniu roboczym, oraz jako karta. No i w tym momencie można automatycznie sprawdzić… wszystko. Na przykład to, czy dany pracownik pracuje na swoim stanowisku, czy siedzi i flirtuje z sekretarką. Z których pomieszczeń korzysta. Albo jak często wychodzi do toalety.

Uczucia, podobnie jak w przypadku kamer mam mieszane. Oczywiście wyobrażam sobie nadużycia ze strony pracodawcy z wykorzystaniem tego typu technologii, ale… nie dajmy się zwariować. Równie dobrze może wykorzystywać tego typu rozwiązania do optymalizacji rozmieszczenia narzędzi/pomieszczeń… Tworzący prawo będą mieli kolejny trudny orzech do zgryzienia.

Czyli klasyczne: narzędzia nie determinują wykorzystania. Pozostało życzyć wszystkim normalnych AKA ludzkich pracodawców, którzy rozsądnie korzystają z narzędzi. I pracowników, których nie trzeba kontrolować na każdym kroku.

Raspberry Pi, Raspbian i problemy z kartami microSD

Jakieś siedem tygodni temu pisałem, że padła mi karta microSD (Kingston) w Raspberry Pi. Wymieniłem na nową (Goodram). Zamontowana oszczędnie, tj. bez journala i z symlinkiem /var/lib/transmission-daemon/info kierującym na dysk twardy. Wczoraj robię aktualizację systemu, a tu nagle:

Preparing to replace libssl1.0.0:armhf 1.0.1e-2+rvt+deb7u7 (using .../libssl1.0.0_1.0.1e-2+rvt+deb7u10_armhf.deb) ...
Unpacking replacement libssl1.0.0:armhf ... dpkg: error processing /var/cache/apt/archives/libssl1.0.0_1.0.1e-2+rvt+deb7u10_armhf.deb (--unpack):
error creating directory `./usr/share/doc/libssl1.0.0': Input/output error
Segmentation fault Segmentation fault -bash: mbrtowc.c:92: __mbrtowc: Assertion `status == __GCONV_OK || status == __GCONV_EMPTY_INPUT || status == __GCONV_ILLEGAL_INPUT || status == __GCONV_INCOMPLETE_INPUT || status == __GCONV_FULL_OUTPUT' failed.

Piękne, prawda? Oczywiście kluczowy jest input/output error. Fsck, są błędy, naprawiony filesystem. Coś mnie tknęło i sprawdziłem badblocks (badblocks -sv). Tak jest, błędy w okolicy 90% karty (dead link). Sztuk prawie 30. Wygląda, że karta Goodram wytrzymała w komfortowych warunkach raptem 7 tygodni. Masakra.

Z tego wszystkiego zacząłem sprawdzać, co pisze na dysk (iotop -ao). Wyniki (sortowane po ilości zapisów, czas działania kilka godzin) są ciekawe:

3192 be/4 root 8.00 K 4.03 M 0.00 % 0.00 % rsyslogd -c5
2184 be/4 root 240.00 K 880.00 K 0.00 % 0.00 % nmbd -D
3341 be/4 ntp 248.00 K 188.00 K 0.00 % 0.00 % ntpd -p /var/run/ntpd.pid -g -u 102:104
5256 be/4 root 0.00 B 160.00 K 0.00 % 0.00 % [kworker/u2:2]
2911 be/4 root 208.00 K 88.00 K 0.00 % 0.00 % -bash

Jak widać, głównie rsyslog. I raczej nie ma tego wiele.

I tu zaczyna się część najciekawsza. Pamiętacie uszkodzoną kartę Kingstona? Przygotowałem się do pozbycia się jej, poleciał shred. Stwierdziłem, że uruchomię badblocks na niej. I… niespodzianka. Teraz nie zgłasza błędów. Ani w teście odczytu (domyślny), ani w niedestrukcyjnym teście zapisu (badblocks -nvs). Naprawiło się?

Zaczynam podejrzewać jakiegoś buga z przejściówką microSD -> SD (ale są dwie różne, bo każda karta miała swoją), gniazdem w rpi (ale działało OK, poza tym i badblocks, i fsck robię w laptopie). Zagadka.

Ostatecznie zmniejszyłem rozmiar partycji ext4 na karcie Kingstona i działa do tej pory bez problemu. Czyli jakieś 3 tygodnie bezproblemowego działania, bo wpis zacząłem tworzyć 12 czerwca.

UPDATE: Zwariowałem. Goodram, który ewidentnie miał błędy, bo nie tylko badblocks je wykazywał, ale nawet shred puszczony przed wyrzuceniem powodował błędy IO i nie mógł dobrnąć do końca (a próbowałem nie raz), teraz działa. Nagrałem Raspbiana dla Banana Pi, test badblockiem i… czysto. WTF?

Software RAID i wypadnięcie dysku – HOWTO

Coś złego zaczęło dziać się z jednym z dysków w jednym z desktopów. Wygląda, jakby startował, a następnie robił restart. Głośne cyknięcie, rozkręcanie się dysku, a w tym czasie system stoi. Albo umiera zasilacz, albo dysk. Albo coś gdzieś nie styka.

Ponieważ w moje ręce wpadł inny dysk, postanowiłem podłączyć go do sprawnego komputera, zdiagnozować, wyzerować i zamienić z dyskiem w padającym desktopie.

Wszystko byłoby fajnie, ale w komputerze, w którym chciałem dokonać diagnostyki jest już software RAID. Po podłączeniu dysku do diagnostyki (IDE) system wstał, ale… tylko z jednym dyskiem (zdegradowany RAID). Podłączanego dysku też nie widział. Efekt był taki, że po odpięciu dysku do diagnostyki i uruchomieniu systemu, przywitał mnie rozjechany RAID (md0):

cat /proc/mdstat 
Personalities : [raid1]
md127 : active (auto-read-only) raid1 sda1[0]
      57584256 blocks super 1.2 [2/1] [U_]
     
md0 : active raid1 sdb2[1]
      57584256 blocks super 1.2 [2/1] [_U]

Natomiast w dmesg widoczny był wpis:

md: kicking non-fresh sda1 from array!

Wszystko jak najbardziej OK, tylko jak teraz poskładać to do kupy? TBH liczyłem, że system sam wykryje, że dysk będący częścią RAID wrócił i że ma stare dane. Czyli zrobi synchronizację. No niestety, nic nie dzieje się automagicznie. Chwila z wyszukiwarką i znalazłem rozwiązanie:

mdadm --stop /dev/md127
mdadm --add /dev/md0 /dev/sda1

Po takich komendach RAID rozpoczął synchronizację, której postęp można sprawdzić przez cat /proc/mdstat.

Tyle w kwestii podłączania dziwnych dysków do desktopa z software RAID. Przyczyną dziwnego zachowania okazało się… moje czytanie instrukcji. Nie zapakowałem dysku jak przyszedł (zlimitowany do 32GB), tylko zmieniłem zworką tryb na auto select. Znaczy tak mi się wydawało, gdyż wszystko wskazuje na to, że opis należy czytać odwrotnie. Jakichkolwiek oznaczeń gdzie dół a gdzie góra oczywiście brak.

Upał

Przejście z jesieni w lato było dość gwałtowne w tym roku. Co prawda wiosna, i to ciepła przyszła już dawno, ale niedawno zrobiło się zimno, pochmurno i w ogóle nieciekawie. Ale od paru dni w Poznaniu zrobiło się lato pełną gębą, z temperaturami rzędu 30 C. Sporo i mocno odczuwalne, z uwagi na gwałtowność zmiany.

Zmiany temperatury o dziwo dotknęły też mojego NAS opartego o Raspberry Pi. Piszę o dziwo, bo w sumie stoi blisko grzejnika i myślałem, że głównie zimą będzie tam gorąco. O ile 40 C na dysku (samo rpi mnie mało interesuje, dopóki się nie wiesza itp.) zostało przekroczone już dawno, to do tej pory utrzymywało się 41-42 C. No chyba, że pojemnik został czymś przykryty, co się zdarzyło raz czy dwa, ale można uznać za nieistotne odstępstwo od normy. Natomiast odkąd zaczęły się upały, dysk zgłaszał cały czas temperatury 44-45 C. Nawet i 46 się zdarzyło, a tak przecież nie mogło zostać. Tym bardziej, że bliźniak leżący luzem (OK, inna lokalizacja) ma w tej chwili 35 C, a 46 to jego życiowy rekord.

Postanowiłem machnąć ręką na uptime (nie, nie zbieram i generalnie nie zwracam uwagi, ale nie lubię wyłączać sprzętu) i dorobić otwory. Z poprzednich sześciu otworów wylotowych u góry obudowy (po 3 sztuki na dwóch ściankach) zrobiło się… 20 (po 5 na każdej ściance). Dodatkowo dorobiłem po 3 sztuki otworów wlotowych w dolnej części ścianek. Mam wrażenie, że filcowe nóżki są jednak trochę za niskie. Zobaczę, czy to coś pomoże… Jeśli nie, to będzie trzeba pomyśleć o jakimś separatorze pomiędzy rpi a kieszenią z dyskiem i może o podwyższeniu nóżek. W sumie w odwrotnej kolejności, bo wpływ podwyższenia nóżek łatwo przetestować prowizorycznie podkładając choćby dwa ołówki. 😉

Przy okazji, skoro już było wyłączenie z prądu, skorzystałem z watomierza i sprawdziłem, ile prądu bierze Raspberry Pi. No, w zasadzie cały zestaw, bo samego rpi nie mierzyłem. Więc hub USB + rpi + dysk 2,5″ biorą u mnie przy normalnym działaniu 5,2W. Przy obciążeniu CPU (prosty Perl) wzrasta to do 5,9W. Najbardziej obciążające jest kopiowanie na dysku USB z partycją NTFS – typowo 7,3W, maksymalnie 8W.