Huomasin jotain merkillistä vasta nyt vaikka päivitin tietokoneeni raudan jo viikkoja sitten melko radikaalisti. Mitä kun top näyttäisi listaavan kaikille prosesseille nollaa %CPU-kentässä? TIME+-kenttä väittää ettei edes Xorg ole käyttänyt yhtään aikaa. Data on selvästi ihan puppua - yleensä raskaan prosessin %CPU voi olla melko alhainenkin jos homma on i/o-bound ja softa vaikka odottaa levyltä dataa, mutta nyt on kyse siitä, että minkään threadin cpu-aika ei näytä olevan mitään. Osoittautui, että kyseessä on BIOS-bugi johon löytyi onneksi päivitys ja että tämä Linux on jotakuinkin kunnossa (vaikka reagoi BIOS-bugiin häiritsevästi mikä voi olla oma buginsa).
En muista havainneeni tätä ongelmaa vielä ollenkaan aiemmin, mikä on hämmentävää, sillä päivitin koko järjestelmää softankin osin varsin aktiivisesti kun likimain kaikki fyysiset osat tietokoneesta vaihtuivat uuteen (käytettyyn, uudempaan kuin omat aiemmat). Yleensä kun tätä gentoota päivittää, niin softia saa kääntää itse sillä paketinhallinta puljaa lähdekoodien eikä binäärien kanssa kuten monesti muualla. Sitä sitten välillä katselee huvikseen että missä homma menee ja paljonko kuormaa prosessoreilla on jne. Tajusin silti vasta nyt että jotain on pielessä.
Olisiko jokin firmispaketti päivittynyt ja sotkenut asioita uuden cpu:n (i7-3930K) kanssa? Jokin ajastin ylivuotanut kernelissä ja bugannut josko kernelversioni olisi räsä? Ettei olisi jokin rootkit asentunut vaikka softa on jotakuinkin uusinta uutta eikä juuri portteja auki ulkomaailmaan - rootkitit yleensä piilottavat ainakin itsensä topista yms? Ehkä kuitenkin ongelma on ollut olemassa uuden hardiksen aikana koko ajan enkä vaan oikeasti ole huomannut? Kellonaika on kuitenkin kohdallaan, ja esim. htopin näyttämät usaget per cpu ovat epänollaa. Oikeastaan vain melkein kaikkien prosessien ajat ovat nollaa - PID 1:n eli initin kohdalla oli enemmän-kuin-0 TIMEä, en nyt muista paljonko.
Hetkisen googlattuani selvisi, etten ole suinkaan ainoa oireileva. Joku Archia käyttävä oli onneksi aiemmin ihmetellyt mistä on kyse. Ketjussa esiintyy jännittäviä kernelviestejä, jotka löytyivät myös omasta lokistani. Relevantteja tsc:hen liittyviä rivejä dmesgistäni:
[ 0.112686] TSC synchronization [CPU#0 -> CPU#1]: [ 0.112693] Measured 12601562437235734 cycles TSC warp between CPUs, turning off TSC clock. [ 0.112702] tsc: Marking TSC unstable due to check_tsc_sync_source failed ... [ 0.948026] clocksource: Switched to clocksource hpet ... [ 1.278829] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2e289303664, max_idle_ns: 440795277071 ns
BIOS-päivitys tosiaan auttoi. Mystiset ongelmat saavat silti aikaan kutinan joka ei lähde vain korjaamalla vaan selvittämällä oireiden lähteen. CPU on tosiaan i7-3930K, ja emolevy on ASUS P9X79, kernelversio 4.9.23 (nyttemmin taas päivitetty). BIOS-versio oli 3501 (julkaistu 14.3.2013) ja päivitin uusimpaan ei-betaan, versio 4701 (23.6.2014). Erot valmistajan supportin mukaan ovat aika geneerisiä:
- Improve system stability.
- Enhance compatibility with some USB device.
- Revise help string in BIOS.
- Fixed Power On By RTC function failed.
- Support Intel IVB-E series CPU.
- Support new CPUs.
- Improve system compatibility.
Veikkaan, että tässä on kyseessä "Improve system compatibility." joita on versioissa 4302 ja 4005. Warp eri corejen välillä meinaa että kello on corejen mielestä eri ajassa. Laskuriin voi myös kirjoittaa WRMSR-assykäskyllä (RDTSC taas lukee TSC:n corelta jolla koodi on ajossa) ja vissiin sitten yhdeltä corelta kirjoittaminen ei synkronoi uutta arvoa kaikille coreille.
Käyttäjänimi mikesart overclock.net-foorumilla kuulemma sai Inteliltä vihjeen, että ehkäpä BIOS sotkee pakkaa:
so the way the hardware works is that there is 1 "master" tsc in the CPU package, that gets started when the cpu package comes out of reset. all logical cpus keep an offset value from that, which starts at 0, and the "master + offset" value is what gets returned on rdtsc. if someone writes to the tsc (using an MSR), what actually happens is that the master tsc does not change, only the per logical cpu offset gets changed.
Linux does not write to the TSC since quite a while... which means the Asus BIOS is doing that. It really should not.
Some bioses write to the TSC to "hide" the cpu cycles used in SMM from the OS..... maybe that is going on here.
Juuri niin, tsc:hen kirjoittaminen päivittää vain yhden coren arvon. Nollaus globaalisti kai kaipaisi sitten resetin. (SMM viittaa tässä system management modeen eli kritisoituun cpu:n sisäiseen NSA-taikakoodiin.) Että kiitti, ASUS. No onneksi nyt on 2017 eikä 2013 jolloin nuo monet muut joita googlella löytyy etsivät ongelmaansa (tämä "Marking TSC unstable due to check_tsc_sync_source failed" tai vastaavaa).
BIOS-päivityksen jälkeen top näyttää korrektit cpu-ajat, ja dmesgistä löytyy seuraavaa:
[ 2.488696] tsc: Refined TSC clocksource calibration: 3201.973 MHz [ 2.488702] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2e27921282e, max_idle_ns: 440795268548 ns ... [ 1.154638] clocksource: Switched to clocksource hpet ... [ 3.496933] clocksource: Switched to clocksource tsc
ja muita "Switched to" ei näy tsc:n jälkeen. Rikkinäisellä tapahtuvaa "TSC synchronizationia" ei näy lainkaan. Tätä clocksourcea voi vaihtaa lennossa echoamalla sopivan taikasanan tempputiedostoon /sys/devices/system/clocksource/clocksource0/current_clocksource (enpä tosin tiedä mikä kaikki näin oikeasti vaihtuu, että pitäisikö bootissa asti kernelin cmdlinellä komentaa). /sys/devices/system/clocksource/clocksource0/available_clocksource listaa saatavilla olevat kellot (itselläni nyt "tsc hpet acpi_pm").
Selvisi tavallaan, miksi biospäivitys korjasi tilanteen. Vielä hämmentää, että miksi aiemmin hpet-clocksourcella cputimet olivat nollaa. Täytynee katsoa vielä syvemmälle.
TSC eli time stamp counter on CPU:n sisäinen rekisteri, joka kasvaa jokaisella kellosykillä. Sitä voi käyttää matalan overheadin ajastukseen. HPET eli high precision event timer on erillinen kellopiiri. Linux käyttää mieluummin TSC:tä ajan laskentaan jos se on järkevästi saatavilla, sillä HPET on ongelmallinen muutamilta osin (mm. kommunikointi sille on hidasta). TSC:ssäkin on omat vaivansa jotka Linux kyllä huomioi.
Viesti "warp between CPUs" merkitsee, että TSC:n arvo ei ole konsistentti eri ytimien kesken, mikä tietysti hankaloittaa ajan laskentaa jos vaikka prosessi sattuu skeduloitumaan corelta toiselle. Linux päättää käyttää HPETiä.
Ookoo. Mutta seinäkelloaika oli oikein ja kaikki muukin vaikutti olevan kunnossa, paitsi prosessien ajat. Miksi tähän tarvittaisiin TSC:tä?
Top on osa procps-nimistä pakettia. Sorsaa tarkastelemalla nähdään, että se lukee %CPU-arvonsa /proc/<pid>/stat:n kautta, mikä nyt oli vaikka paketin nimestäkin arvattavissa. Seuraavaksi liikahdetaan kerneliin ja etsitään paikka, jossa tuo tulostetaan.
do_task_stat hakee threadgroupin user- ja system-timen, jotka thread_group_cputime vain summaa eri taskeista. Greppaillaan utimeä ja stimeä ympäriinsä ja huomataan, että ne kasvavat per tick muiden laskurien kanssa. Tai siis niiden pitäisi kasvaa, mutta eivät vissiin muutu paitsi initin osalta.
Tässä välissä huomataan, että dokumentaatio mainitsee update_process_timesin yhteydessä per-cpu hrtimerit. TSC lienee eräs hrtimer koska sen resoluutio on luonnollisesti hyvin korkea, ja mitä jos se TSC on kytketty pois? Mutta jos samasta periodic tickistä ajetaan myös mm. jiffiesiä, joka on hyvin keskeinen Linuxin aikakäsite jota ilman oikein mikään ei toimi, ja jos kerran prosessien ajat eivät päivity mutta jiffies päivittyy silti niin mitähän kummaa? Ja kernelihän sanoi käyttävänsä clocksourcea hpet.
Usealle arkkitehtuurille on omat paikkansa jotka kutsuvat update_process_timesiä. x86:lla on vain maininta aiheesta apic-interruptin yhteydessä, mutta eikö apic-timer ole taas kolmas TSC:n ja HPET:n kaveriksi. Yleisessä koodissa on tick_sched_handle ja tick_periodic jotka tuota kutsuvat, ja näin syvällä coressa en jaksa uskoa vian olevan. Voi toki olla että katson täysin väärään suuntaan, ehkä jokin muu top:n skaalauksessa mukana ollut oli väärin. Laskikohan kone edes uptimeä?
Enpä kuitenkaan jaksa downgradettaa bios-vikaa takaisin, jotta juttua selvittäisi taas reaaliajassa. Tuskinpa myöskään clocksourcen asettaminen hpetiksi bootissa aiheuttaisi tätä, koska sehän olisi ihan tyhmää (ja silloin tsc silti toimisi). Jään ihmettelemään.
0 kommenttia
Oma kommenttisi
Mielipide tämän sivun asiasta? Kirjoita toki. Älä raapusta kuitenkaan ihan asiattomia juttuja.
Jos on yksityisempää asiaa, tarkkaa kysyttävää tai aihetta pidemmälle keskustelulle, käytä yhteydenottolomaketta kommentoinnin sijaan.
Hölmöt kommentit saatetaan moderoida pois jälkikäteen.