Dotaz: proces ve stavu "uninterruptible sleep"

[Bill Gates]

Muze mi nekdo vysvetlit proc se proces dostane do stavu "uninterruptible sleep" a visi v nem donekonecna? Ceka se na zarizeni? Neodpovida? Tak jako proces na to zarizeni budu cekat donekonecna a budu viset v systemu az do restartu? K cemu je to dobre? K brzke nutnosti fyzickemu restartu systemu? Prosim nekdo mi to vysvetlete k cemu je dobre ze se proces dostane do tohoto stavu a neni mozne s tim nic delat. Ani ho killnout.

Odpovědi

[Bill Gates]

problemem byl sshfs, ktery nemel duvod nefungovat, slo o hostonly spojeni mezi hostem a hostitelem ve virtualboxu, nicmene logika kdy proces ceka donekonecna bez vyhlaseni chyby po nejakem timeoutu (byt by byl bug ve virtualboxu, nebo v sshfs, to je jedno) mi prijde kontraproduktivni. Nebo ma to nejaky vyznam drzet proces ve stavu uninterruptible sleep?

[rastos]

"uninterruptible sleep" napr. nastáva, keď proces čaká na HW. Ak sa čaká krátko, tak si to ani nevšimneš. Niektoré zariadenia majú definované max. doby odozvy a preto sa asi nepovažuje za nutné kontrolovať softwareovo, či bola prekročená nejaká rozumná doba. Navyše, aj keď by sa systém rozhodol prerušiť čakanie na HW, čo s tým? Nechať zariadenie v nedefinovanom stave? Lepšie je čakať a dúfať, že sa z toho HW zotaví.

[Bill Gates]

jj, ja zhruba chapu proc se to stava, ale otazka je jestli je to lepsi cekat donekonecna nebo ne. Pri predstave ze je na to pripojen treba apache a ze sitovky se na nej hrnou requesty, tak je cely apache v momente ve stavu D a nazdar bazar. Pritom neslo o fyzickou chybu HW ale o sshfs v nejakem nedefinovanem stavu. V tu chvili apache stoji, a request z browseru ceka donekonecna. Kdyby se apache nedostal do stavu D a po chvili vyhodil do browseru chybu, bylo by to lepsi, mohl by se pak venovat necemu uzitecnejsimu nez cekani na zarizeni. Ve stavu D nemuze apache vyrizovat dalsi pozadavky, ktere by vyridit treba mohl, protoze zarizeni, ktere jsou potrebne pro jine ukoly v chybovem stavu treba nejsou. Me to prijde neprakticke nechat proces vytuhly a cekajici a jeste navic nekillnutelny. Pokud zarizeni nefunguje spravne, tak by se IMHO na neho system mel vykaslat (samozrejme problem patricne nareportovat) a fungovat alespon s tim co jede, tedy aspon ja tak uvazuju kdyz nejakou aplikaci pisu. Prijde mi divne kvuli problemu s HW zablokovat celou viceprocesorovou nebo vicevlaknovou aplikaci. Jedna se o Debian Lenny.

[otokar]

Jak má OS vědět, že zařízení neodpovídá, protože je kouslé, nebo protože pouze čeká, až dokončí nějakou smysluplnou, byť dlouho trvající činnost? IMHO je smysluplnější opravit aplikaci tak, aby podobné stavy měla ošetřeny a ne patchovat kernel. Kromě toho pokud se procesy dostávají do D stavu nějak častěji, je to známka nějakého problému a ignorováním problému se, jak známo, tento neodstraní..

[michich]

Trčení ve stavu D aplikace nemá jak ovlivnit. Považujoval bych to za chybu kernelu.

[Bill Gates]

no prave .. a navic bych rekl, ze pokud jsem tohle dokazal nehardwarove (jen softwarove) diky kousanci sshfs, tak je to docela i mozny bezpecnostni problem. Nicmene D stavy jsou v jadre uz dyl, co tedy vim. Divné ...

[Ash]

Zkuste se zazajímat jestli u sshfs neexistuje také nějaká možnost soft mountu, či interruptable mountu jako je tomu u nfs. Pokud ne, pokládal bych to za nedostatek sshfs protokolu. Předpokládám že se váš proces z D nedostane ani když zkusíte zařízení umountnout lazy (umount -l), pokud nevíte tak to zkuste.

Další možnost by byla síťovka a problém s jejím ovladačem (u síťovek se tak nějak předpokládá že prostě budou fungovat) ale u vás je to zdá se čistě problém sshfs takže ovladač asi nebude váš případ.

[Bill Gates]

umount nesel. Samotny pristup k adresari ktery byl mountnuty zpusobil tuhost konzole, i midnight commanderu. Jedine co to z toho stavu dostalo bylo nasilne kill -9 procesu, ktery sshfs zajistoval. Sitovky byly pouze softwarove, slo o vboxnet - klasika hostonly adapter mezi hostem a hostitelem u virualboxu. Tezko rict co to zpusobilo. I logy jsem prohlizel nekolikrat ve snaze prijit na to co se dálo.

umount -l muzu vyzkouset pokud se to priste stane.

[Ash]

U mně to dělá nfs když přestane být server dostupný (vypnu NAS :) Rovněž v takovém případě stačí zabít mc či shell, nfs navíc má možnost toho soft mountu která by si s tím asi poradila. sshfs přímo moc nepoužívám, používám spíš FISH v mc (to se chová podobně, třeba při výpadku spojení či změně routování na vpn :)

[michich]

Navíc v kódu NFS v kernelu se od nějaké doby na některých místech místo úplně nepřerušitelného blokování používá stav "killable", který sice navenek vypadá stejně (ve výpisu je pořád "D"), ale reaguje to aspoň na SIGKILL. Nevím, jak je to u FUSE.

[Bill Gates]

umount -l tedy dnes fungoval. novy mount pak ale vytvoril nove ssh spojeni a aplikace zustaly ve stavu D.

[Bill Gates]

Tak super. Dneska po ranu jsme ve stejnem stavu jako vcera. No to mam teda fakt radost ze mam zas co na praci (hledat nasekane bugy v OS, coz nikdo nezaplati), to fakt potesi :(

24027 ?        D      0:00 /usr/sbin/apache2 -k start
24030 ?        D      0:00 /usr/sbin/apache2 -k start
24037 ?        D      0:00 /usr/sbin/apache2 -k start
24040 ?        S      0:00 /usr/sbin/apache2 -k start
24057 ?        D      0:00 /usr/sbin/apache2 -k start
24063 ?        D      0:00 /usr/sbin/apache2 -k start
24064 ?        D      0:00 /usr/sbin/apache2 -k start
24065 ?        D      0:00 /usr/sbin/apache2 -k start
24066 ?        D      0:00 /usr/sbin/apache2 -k start
24067 ?        D      0:00 /usr/sbin/apache2 -k start
24068 ?        D      0:00 /usr/sbin/apache2 -k start
24069 ?        D      0:00 /usr/sbin/apache2 -k start
24085 ?        D      0:00 /usr/sbin/apache2 -k start
24086 ?        D      0:00 /usr/sbin/apache2 -k start
24087 ?        D      0:00 /usr/sbin/apache2 -k start
24094 ?        D      0:00 /usr/sbin/apache2 -k start
24095 ?        D      0:00 /usr/sbin/apache2 -k start
24096 ?        D      0:00 /usr/sbin/apache2 -k start
24097 ?        D      0:00 /usr/sbin/apache2 -k start
24098 ?        D      0:00 /usr/sbin/apache2 -k start
24099 ?        D      0:00 /usr/sbin/apache2 -k start
24100 ?        D      0:00 /usr/sbin/apache2 -k start
24101 ?        D      0:00 /usr/sbin/apache2 -k start
24102 ?        D      0:00 /usr/sbin/apache2 -k start
24103 ?        D      0:00 /usr/sbin/apache2 -k start
24104 ?        D      0:00 /usr/sbin/apache2 -k start
24107 ?        D      0:00 /usr/sbin/apache2 -k start
24108 ?        D      0:00 /usr/sbin/apache2 -k start
24109 ?        D      0:00 /usr/sbin/apache2 -k start
24110 ?        D      0:00 /usr/sbin/apache2 -k start
24115 ?        D      0:00 /usr/sbin/apache2 -k start
24116 ?        D      0:00 /usr/sbin/apache2 -k start
24117 ?        D      0:00 /usr/sbin/apache2 -k start
24118 ?        D      0:00 /usr/sbin/apache2 -k start
24119 ?        D      0:00 /usr/sbin/apache2 -k start
24120 ?        D      0:00 /usr/sbin/apache2 -k start
24121 ?        D      0:00 /usr/sbin/apache2 -k start
24122 ?        D      0:00 /usr/sbin/apache2 -k start
24123 ?        D      0:00 /usr/sbin/apache2 -k start
24124 ?        D      0:00 /usr/sbin/apache2 -k start
24125 ?        D      0:00 /usr/sbin/apache2 -k start
24126 ?        D      0:00 /usr/sbin/apache2 -k start
24127 ?        D      0:00 /usr/sbin/apache2 -k start
24128 ?        D      0:00 /usr/sbin/apache2 -k start
24129 ?        D      0:00 /usr/sbin/apache2 -k start
24131 ?        D      0:00 /usr/sbin/apache2 -k start
24132 ?        D      0:00 /usr/sbin/apache2 -k start
24133 ?        D      0:00 /usr/sbin/apache2 -k start
24135 ?        D      0:00 /usr/sbin/apache2 -k start
24136 ?        D      0:00 /usr/sbin/apache2 -k start
24137 ?        D      0:00 /usr/sbin/apache2 -k start
24138 ?        D      0:00 /usr/sbin/apache2 -k start
24139 ?        D      0:00 /usr/sbin/apache2 -k start
24140 ?        D      0:00 /usr/sbin/apache2 -k start
24141 ?        D      0:00 /usr/sbin/apache2 -k start
24142 ?        D      0:00 /usr/sbin/apache2 -k start
24143 ?        D      0:00 /usr/sbin/apache2 -k start

[Bill Gates]

Podle jiste zalezitosti, ktera se mi refreshuje kazde 2 minuty bych rekl ze se to stalo nekdy kolem pul seste rano. Jdu se podivat do logu na tu dobu. Pokud ma nekdo tip na co se jeste podivat tak sem s tim. Mam to ted ve vytuhnutem stavu.

[michich]

Vypiš si cat /proc/$PID/stack pro některé z těchto procesů. Nebo proveď Alt+SysRq+T (nebo echo t > /proc/sysrq-trigger), to vypíše stack všech procesů do dmesg.

[Bill Gates]

24136 ?        D      0:00 /usr/sbin/apache2 -k start
24143 ?        D      0:00 /usr/sbin/apache2 -k start

[09:30:15]-[/etc/default]
[root@develop]# cat /proc/24143/stack
cat: /proc/24143/stack: No such file or directory

[09:30:26]-[/etc/default]
[root@develop]# cat /proc/24136/stack
cat: /proc/24136/stack: No such file or directory

[root@develop]# echo t > /proc/sysrq-trigger
v /var/log/dmesg bezezmeny
chvili to ale neco delalo (par sekund)

[Bill Gates]

Příloha:

• messages (191134 bytů)

Vypsal to do messages. V priloze.

[Bill Gates]

Feb 11 06:25:04 develop rsyslogd: [origin software="rsyslogd" swVersion="3.18.6" x-pid="2015" x-info="http://www.rsyslog.com"] restart
Feb 11 06:27:36 develop ntpd[2268]: adjusting local clock by -3545.390981s
Feb 11 06:27:36 develop ntpd[2268]: adjtime failed: Invalid argument
Feb 11 06:30:36 develop ntpd[2268]: adjusting local clock by -3545.376907s
Feb 11 06:30:36 develop ntpd[2268]: adjtime failed: Invalid argument

Ze by rozjety cas na obou strojich mel na tohle vliv? Neco jako kdyz dovecot lehne jen kvuli zmene casu? No to snad ne...

A pak jsou v logu tyhlety nádhery:

Feb 11 09:34:50 develop kernel: [243449.485638] INFO: task apache2:24023 blocked for more than 120 seconds.
Feb 11 09:34:50 develop kernel: [243449.487735] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 11 09:34:50 develop kernel: [243449.488082] apache2       D 00000000     0 24023  17248
Feb 11 09:34:50 develop kernel: [243449.488196]        d20d1a40 000000c4 00000001 00000000 00000090 d20d1bcc c1309fc0 00000000
Feb 11 09:34:50 develop kernel: [243449.488411]        0008ac30 039ec3b4 00000090 c011b733 00000000 00000000 00000000 000000ff
Feb 11 09:34:50 develop kernel: [243449.489222]        d64d7eb8 d64d7ec0 d64d7ebc d20d1a40 c02b9436 d7d51de8 c1565de8 d20d1a40
Feb 11 09:34:50 develop kernel: [243449.489418] Call Trace:
Feb 11 09:34:50 develop kernel: [243449.489557]  [<c011b733>] try_to_wake_up+0xe8/0xf1
Feb 11 09:34:50 develop kernel: [243449.489661]  [<c02b9436>] __mutex_lock_slowpath+0x50/0x7b
Feb 11 09:34:50 develop kernel: [243449.489744]  [<c02b92cc>] mutex_lock+0xa/0xb
Feb 11 09:34:50 develop kernel: [243449.489808]  [<c017aa7b>] do_lookup+0x6e/0x153
Feb 11 09:34:50 develop kernel: [243449.489882]  [<c017c262>] __link_path_walk+0x2c4/0xb26
Feb 11 09:34:50 develop kernel: [243449.489953]  [<c0182b36>] dput+0x15/0xbb
Feb 11 09:34:50 develop kernel: [243449.490021]  [<c017caa9>] __link_path_walk+0xb0b/0xb26
Feb 11 09:34:50 develop kernel: [243449.490092]  [<c017cafb>] path_walk+0x37/0x70
Feb 11 09:34:50 develop kernel: [243449.490161]  [<c017cdaa>] do_path_lookup+0x122/0x184
Feb 11 09:34:50 develop kernel: [243449.490231]  [<c017d78c>] __path_lookup_intent_open+0x42/0x72
Feb 11 09:34:50 develop kernel: [243449.490514]  [<c017d80b>] path_lookup_open+0xf/0x13
Feb 11 09:34:50 develop kernel: [243449.490586]  [<c017d896>] do_filp_open+0x87/0x684
Feb 11 09:34:50 develop kernel: [243449.490658]  [<c0164050>] handle_mm_fault+0x291/0x6dd
Feb 11 09:34:50 develop kernel: [243449.490743]  [<c0173094>] do_sys_open+0x40/0xb0
Feb 11 09:34:50 develop kernel: [243449.490816]  [<c0173148>] sys_open+0x1e/0x23
Feb 11 09:34:50 develop kernel: [243449.490885]  [<c01038d2>] syscall_call+0x7/0xb
Feb 11 09:34:50 develop kernel: [243449.490965]  =======================

[chochi]

Bug v sshfs? Zkus pustit sshfs v debug modu (nakem dopsat "sshfs_debug"), aby bylo vydet kde se to zasekne.
Podle stack trace kernelu Apache se chce podivat do adresare, jehoz inode je zamknut - pravdepodobne v sshfs.
FUSE funguje tak ze pro nektere operace zamkne inode - zavola funkci v user space - odemkne indoe. Takze pokud se FUSE aplikace zasekne v nejake funkci tak pristup k danemu indou zpusobi "uninterruptible sleep".
Takze mozne reseni: zjistit proc se zasekava sshfs, nebo nakounfigurovat Apache at neleze do adresaru ktere maji neco spolecneho se sshfs.

[Bill Gates]

Uvazoval jsem predchvili o prechod na neco jineho, treba NFS ale sshfs mi vyhovuje v nekolika specifickych vecech, ktere urcite jdou i v NFS ale ted neni moc casu na studium jak nektere veci zaridit aby fungovaly podobne. Ve finale jsem to ted vyresil restartem hosta i hostitele, protoze mam jeste pocit ze jsem upgradoval hosta a od te doby nerestartl. Jestli se to ted neprojevi, tak to muze byt taky pricina ten upgrade bez restartu. Pokud se to projevi i zitra (nebo nekdy ted v blizke dobe) tak by to mohl byt bug a asi bych tedy premyslel o prechodu na NFS. No uvidime co to ted udela.

[Bill Gates]

krasne neprerusitelně vytuhlé rano. Tak jsem nejak dnes vytuhl pres noc u PC i ja pri vyvoji jiste veci (jeste jsem nespal :D ) a pred chvili bylo 6:30 a opet se projevil problem s sshfs. Mam pocit ze uz vim souvislost. Vcera to bylo totez, kdyz jsem zkoumal log. Rotace logů. Logy rotuji pred 6:30 a vzdy v 6:30 se problem projevi..

Problem nastal ihned po:

Feb 12 06:25:04 develop kernel: imklog 3.18.6, log source = /proc/kmsg started.
Feb 12 06:25:04 develop rsyslogd: [origin software="rsyslogd" swVersion="3.18.6" x-pid="1900" x-info="http://www.rsyslog.com"] restart

Ted otazka co s tim.. Jdu premyslet, kazdopadne ted uz to nasilne odtuhnu a jedem dal. Na neco ale musim prijit.

[Chytrex]

Podívej se do nastavení logrotate a případně jako postrotate přidej restart toho co ti to zasekává:)