[ pisac @ 14.08.2013. 16:05 ] @
Napravio sam jednu prostu skriptu za drndanje hard diska do besvesti (tj. za burn test):

Code:

#!/bin/bash

while :;
do
        RND=$RANDOM;
        echo "Punim TEST${RND}K..."
        dd if=/dev/zero of=TEST${RND}K bs=8k count=$((${RND}/8))k;
        if [ "$?" != "0" ]; then
                echo -n "Trazim fajl za brisanje..."
                RND2=$RANDOM
                until [ -e TEST${RND2}K ];
                do
                        RND2=$RANDOM;
                done
                echo "*** Brisem TEST${RND2}K!"
                rm TEST${RND2}K
        fi
done


Startujem recimo 10 instanci, i onda sa posebnom skriptom pratim ukupnu brzinu upisa na HD na osnovu informacija sa `df`. To je lepo radilo nekih 70 sati, a onda je stalo! Sve instance su bile smrznute, sistemsko opterećenje procesora je bilo 100%, startovanje nove instance te skripte je na tom testiranom hard disku dovodilo do smrzavanja skripte (ne može da se ugasi sa ctrl-c), dok je na drugim hard diskovima radilo bez problema.

U pitanju je glanc nov hard disk. Ext4 fajl sistem.

Sve u svemu, nakon restarta kompjutera je sve nastavilo da radi, ali mene zanima zašto je uopšte bilo blokirano, da li je do HD-a ili do sistema? Bilo je 9 procesa koji su punili sistemsko opterećenje do 100%, a to su 8 dd-a (iako bi trebalo da ih je 10), i u naslovu spomenuti [flush-8:16].

Čemu služi dotični flush?

[Ovu poruku je menjao pisac dana 15.08.2013. u 00:51 GMT+1]
[ pisac @ 15.08.2013. 03:26 ] @
Nađoh čemu služi:

Citat:
Flushing out pdflush
The kernel page cache contains in-memory copies of data blocks belonging to files kept in persistent storage. Pages which are written to by a processor, but not yet written to disk, are accumulated in cache and are known as "dirty" pages. The amount of dirty memory is listed in /proc/meminfo. Pages in the cache are flushed to disk after an interval of 30 seconds. Pdflush is a set of kernel threads which are responsible for writing the dirty pages to disk, either explicitly in response to a sync() call, or implicitly in cases when the page cache runs out of pages, if the pages have been in memory for too long, or there are too many dirty pages in the page cache (as specified by /proc/sys/vm/dirty_ratio).


Dakle, jasno je da je to proces koji je trebao da smandrlja "prljave" blokove iz memorije na disk. I jasno je da se u jednom trenutku sve zapelo sa 100% sistemskog opterećenja procesora.

Ono što mi nije jasno je da li je razlog neispravan HD, ili je razlog neki bag?

Inače, ext4 je bio montiran sa "nobarrier" opcijom.
[ Stator @ 21.08.2013. 14:14 ] @
Jako je tesko da ne kazem nemoguce reci sta je po sredi sa ovom kolicinom informacija.

Baci barem distribuciju / kernel i pun log. Moguce da ni to nece biti dosta. Verovatno da ce morati da setujes kdump i kada se to desi da se trigeruje kernel panic pa da se pogleda u dumpu sta je po sredi.
[ pisac @ 06.09.2013. 10:03 ] @
Linux Slackware14 3.2.29 #2 SMP Mon Sep 17 14:19:22 CDT 2012 x86_64 Intel(R) Core(TM) i7-3770 CPU @ 3.40GHz GenuineIntel GNU/Linux

Ne znam na koji log misliš, ovo sam našao u syslog-u, za svih 10 dd-a koji su bili blokirani:

Aug 17 10:26:21 Slackware14 kernel: [237463.384546] INFO: task dd:25167 blocked for more than 120 seconds.
Aug 17 10:26:21 Slackware14 kernel: [237463.384550] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 17 10:26:21 Slackware14 kernel: [237463.384558] ffff88031f7d3888 0000000000000086 ffff8803e9793dd0 000000010e229cf5
Aug 17 10:26:21 Slackware14 kernel: [237463.384562] ffff880403965960 ffff88031f7d3fd8 ffff88031f7d3fd8 ffff88031f7d3fd8
Aug 17 10:26:21 Slackware14 kernel: [237463.384565] ffff88040388a940 ffff880403965960 0000000000000001 000000011f2d1c40
Aug 17 10:26:21 Slackware14 kernel: [237463.384569] Call Trace:
Aug 17 10:26:21 Slackware14 kernel: [237463.384577] [<ffffffff81b2caef>] schedule+0x3f/0x60
Aug 17 10:26:21 Slackware14 kernel: [237463.384581] [<ffffffff81b2d064>] schedule_timeout+0x1f4/0x310
Aug 17 10:26:21 Slackware14 kernel: [237463.384594] [<ffffffff81061a38>] ? lock_timer_base.isra.31+0x38/0x70
Aug 17 10:26:21 Slackware14 kernel: [237463.384596] [<ffffffff81b2c912>] wait_for_common+0xd2/0x170
Aug 17 10:26:21 Slackware14 kernel: [237463.384598] [<ffffffff8104baf0>] ? try_to_wake_up+0x290/0x290
Aug 17 10:26:21 Slackware14 kernel: [237463.384600] [<ffffffff81b2caad>] wait_for_completion+0x1d/0x20
Aug 17 10:26:21 Slackware14 kernel: [237463.384603] [<ffffffff8115ae4c>] writeback_inodes_sb_nr+0x7c/0xa0
Aug 17 10:26:21 Slackware14 kernel: [237463.384605] [<ffffffff81140101>] ? follow_up+0x31/0xb0
Aug 17 10:26:21 Slackware14 kernel: [237463.384607] [<ffffffff8115ae9e>] writeback_inodes_sb+0x2e/0x40
Aug 17 10:26:21 Slackware14 kernel: [237463.384609] [<ffffffff8115aef4>] writeback_inodes_sb_if_idle+0x44/0x60
Aug 17 10:26:21 Slackware14 kernel: [237463.384611] [<ffffffff812192ba>] ext4_nonda_switch+0x8a/0xa0
Aug 17 10:26:21 Slackware14 kernel: [237463.384613] [<ffffffff8121c782>] ext4_da_write_begin+0x42/0x200
Aug 17 10:26:21 Slackware14 kernel: [237463.384616] [<ffffffff810e6dd6>] generic_file_buffered_write+0x116/0x280
Aug 17 10:26:21 Slackware14 kernel: [237463.384619] [<ffffffff810e8a5a>] __generic_file_aio_write+0x22a/0x440
Aug 17 10:26:21 Slackware14 kernel: [237463.384621] [<ffffffff810e78be>] ? find_get_page+0x1e/0xa0
Aug 17 10:26:21 Slackware14 kernel: [237463.384623] [<ffffffff810e8ce1>] generic_file_aio_write+0x71/0xe0
Aug 17 10:26:21 Slackware14 kernel: [237463.384626] [<ffffffff8121627f>] ext4_file_write+0xaf/0x250
Aug 17 10:26:21 Slackware14 kernel: [237463.384628] [<ffffffff81044cef>] ? pick_next_task_fair+0xef/0x150
Aug 17 10:26:21 Slackware14 kernel: [237463.384631] [<ffffffff81133a06>] do_sync_write+0xe6/0x120
Aug 17 10:26:21 Slackware14 kernel: [237463.384633] [<ffffffff815329fc>] ? security_file_permission+0x2c/0xb0
Aug 17 10:26:21 Slackware14 kernel: [237463.384635] [<ffffffff81133fc1>] ? rw_verify_area+0x61/0xf0
Aug 17 10:26:21 Slackware14 kernel: [237463.384637] [<ffffffff811342dc>] vfs_write+0xac/0x180
Aug 17 10:26:21 Slackware14 kernel: [237463.384639] [<ffffffff8113460a>] sys_write+0x4a/0x90
Aug 17 10:26:21 Slackware14 kernel: [237463.384641] [<ffffffff81b2f26b>] system_call_fastpath+0x16/0x1b


Inače sve se ponovilo identično nakon sledećih oko 100 sati testiranja. Posle nisam testirao.

Što se tiče kdump-a i ostalih zavrzlama, reci preciznije gde kako i šta, pošto se nisam bavio sličnim isterivanjem bagova, pa da probam.
[ pisac @ 06.09.2013. 10:10 ] @
A samo ovo sam našao u messages:

Aug 17 10:26:21 Slackware14 kernel: [237463.384552] dd D ffff88041f2d1c40 0 25167 1125 0x00000000
Aug 17 10:26:21 Slackware14 kernel: [237463.384644] dd D ffff88041f251c40 0 25191 1127 0x00000000
Aug 17 10:26:21 Slackware14 kernel: [237463.384699] dd D ffff88041f291c40 0 25208 1139 0x00000000
Aug 17 10:26:21 Slackware14 kernel: [237463.384751] dd D ffff88041f291c40 0 25221 1131 0x00000000
Aug 17 10:26:21 Slackware14 kernel: [237463.384801] dd D ffff88041f3d1c40 0 25222 1141 0x00000000
Aug 17 10:26:21 Slackware14 kernel: [237463.384850] dd D ffff88041f311c40 0 25223 1135 0x00000000
Aug 17 10:26:21 Slackware14 kernel: [237463.384903] dd D ffff88041f351c40 0 25224 1133 0x00000000
Aug 17 10:28:21 Slackware14 kernel: [237583.315053] dd D ffff88041f2d1c40 0 25167 1125 0x00000000
Aug 17 10:28:21 Slackware14 kernel: [237583.315147] dd D ffff88041f251c40 0 25191 1127 0x00000000
Aug 17 10:28:21 Slackware14 kernel: [237583.315201] dd D ffff88041f291c40 0 25208 1139 0x00000000
[ pisac @ 07.09.2013. 12:51 ] @
Juče sam pustio test i opet se munjevito blokirao posle već par sati. Što je već sasvim zabrinjavajuće. Međutim, u syslogu sam našao prvo ovo:

Sep 6 14:27:30 Slackware14 kernel: [255812.740456] INFO: task jbd2/sdf5-8:26401 blocked for more than 120 seconds.
Sep 6 14:27:30 Slackware14 kernel: [255812.740458] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Sep 6 14:27:30 Slackware14 kernel: [255812.740462] ffff88030c69bb40 0000000000000046 ffff88030c69bb00 ffffffff00000000
Sep 6 14:27:30 Slackware14 kernel: [255812.740464] ffff8804038a2260 ffff88030c69bfd8 ffff88030c69bfd8 ffff88030c69bfd8
Sep 6 14:27:30 Slackware14 kernel: [255812.740466] ffffffff8200d020 ffff8804038a2260 ffff88030c69bb00 000000010c69bb00
Sep 6 14:27:30 Slackware14 kernel: [255812.740468] Call Trace:
Sep 6 14:27:30 Slackware14 kernel: [255812.740473] [<ffffffff810e7150>] ? __lock_page+0x70/0x70
Sep 6 14:27:30 Slackware14 kernel: [255812.740477] [<ffffffff81b2caef>] schedule+0x3f/0x60
Sep 6 14:27:30 Slackware14 kernel: [255812.740478] [<ffffffff81b2cb9f>] io_schedule+0x8f/0xd0
Sep 6 14:27:30 Slackware14 kernel: [255812.740480] [<ffffffff810e715e>] sleep_on_page+0xe/0x20
Sep 6 14:27:30 Slackware14 kernel: [255812.740481] [<ffffffff81b2d390>] __wait_on_bit+0x60/0x90
Sep 6 14:27:30 Slackware14 kernel: [255812.740483] [<ffffffff810e7290>] wait_on_page_bit+0x80/0x90
Sep 6 14:27:30 Slackware14 kernel: [255812.740486] [<ffffffff810749a0>] ? autoremove_wake_function+0x40/0x40
Sep 6 14:27:30 Slackware14 kernel: [255812.740488] [<ffffffff810e7731>] filemap_fdatawait_range+0x101/0x190
Sep 6 14:27:30 Slackware14 kernel: [255812.740490] [<ffffffff810e77eb>] filemap_fdatawait+0x2b/0x30
Sep 6 14:27:30 Slackware14 kernel: [255812.740493] [<ffffffff81265c09>] jbd2_journal_commit_transaction+0x7c9/0x1720
Sep 6 14:27:30 Slackware14 kernel: [255812.740496] [<ffffffff8126a039>] kjournald2+0xb9/0x220
Sep 6 14:27:30 Slackware14 kernel: [255812.740498] [<ffffffff81074960>] ? finish_wait+0x80/0x80
Sep 6 14:27:30 Slackware14 kernel: [255812.740499] [<ffffffff81269f80>] ? commit_timeout+0x10/0x10
Sep 6 14:27:30 Slackware14 kernel: [255812.740501] [<ffffffff810741ac>] kthread+0x8c/0xa0
Sep 6 14:27:30 Slackware14 kernel: [255812.740503] [<ffffffff81b310b4>] kernel_thread_helper+0x4/0x10
Sep 6 14:27:30 Slackware14 kernel: [255812.740505] [<ffffffff81074120>] ? queue_kthread_work+0xa0/0xa0
Sep 6 14:27:30 Slackware14 kernel: [255812.740506] [<ffffffff81b310b0>] ? gs_change+0xb/0xb


a odmah posle je logovana i blokada dd-a (radio je samo jedan dd svo vreme, nisam startovao deset istovremeno). I naravno, flush se javlja sa 100% zauzeća kada otkucam top.

jbd2 je u stvari posrednik između sistema i ext4 žurnala. Tako da sam postao ubeđen da je ovo bag u kernelu prilikom rada sa ext4 fajl sistemom. Inače ext4 je drastično brži od ext3 po ovim mojim burn-testovima.

Ne znam da li postoji neki razlog zašto je sada blokada nastupila već posle par sati umesto 70-100 sati, ali možda je jedan od razloga i to što sam disk sada spojio na drugi kontroler na ploči.
[ pisac @ 10.09.2013. 21:38 ] @
Definitivno je neki bag sa ext4 u pitanju.

Formatirao sam isti 3TB disk u ext3, i nema zaglavljivanja. Uzeo sam uz to neki praistorijski disk od 80GB i formatirao ga u ext4, i zaglavio se (jbd2, dd, flush) posle desetak sati.

Znači, definitivno se zaglavljuje samo sa ext4.

Pitanje za upućene:

Sada me muči, šta uraditi sa tim saznanjem? Kome poslati, kako uraditi dump? Gde videti da li je bag već uočen?

Konkretno nisam našao na Internetu da je neki (odgovarajući po posledicama) bag u ovom kernelu ispravljen u nekom sledećem, ali ima nekolicina ext4 jbd2 pomenutih bagova koje ne mogu da dovedem u direktnu vezu sa ovim ponašanjem.
[ HeYoo @ 11.09.2013. 00:34 ] @
Pa mozda dolazi do pregrevanja hdd-a ili nesto slicno. Verovatno da diskovi ne mogu neograniceno dugo raditi bez greske pod takvim mucenjem, ipak je to mehanika. To sto se to ne desava sa ext3 ne znaci automatski da postoji neki bug sa ext4. Cak je malo verovatno da postoji bug ali ko zna. Ne znam da li ti mozda vredi da ocitas S.M.A.R.T.
[ pisac @ 11.09.2013. 19:03 ] @
Sve sam ja iščitao i proverio (uključujući i temperaturu) još pre nego što sam postavio prvi post.
[ Stator @ 16.09.2013. 15:24 ] @
Nisam bas 100% siguran da je problem samo sa EXT4. aj uradi

cat /sys/block/sda/queue/scheduler

sda zameni sa diskom koga maltretiras.

echo deadline > /sys/block/sda/queue/scheduler

naravno opet zameni sda sa pravim diskom.
Pa probaj onda.

Ovo setovanje *nece* preziveti reboot.

Ukoliko i ovo ne pomogne moraces da uzmes da instaliras i konfigurises kdump
Nazalost ovo nije user friendly alat i zahteva poznavanja osnove rada linux kernel-a.
Jako lepo upuctvno se moze naci ovde http://www.dedoimedo.com/computers/kdump.html
Ima i PDF iznad.

Ne ocekuj mnogo pomoci od developer-a, jer koristis dosta staru verziju kernela a verovatno i ostatka, tako da ce verovatno prvo traziti da budes up-to-date sa upstrem-om.
[ pisac @ 12.10.2013. 04:33 ] @
Onaj predlog sa schedulerom nije dao rezultat. U međuvremenu sam stavio kernel 3.2.45, pa zatim 3.10.14, ali ni to nije dalo rezultate, pa sam vratio 3.2.45

Nisam se patio sa kdumpom za sada, ali imam nameru da se uskoro patim sa tjunovanjem ext4 fajll-sistema, da vidim da li isključenje neke od opcija eliminiše bag. Recimo prva koja mi pada napamet je naravno extents.

Inače sam, pošto bag nije lociran, sve diskove/raidove (sa pravim podacima) na dotičnom kompjuteru vratio na ext3, jer mi je važnija pouzdanost nego brzina.
[ Stator @ 18.10.2013. 10:05 ] @
E sada si me bas zainteresovao, imam kuci neki stariji laptop sto mi skuplja prasinu pa cu bas da probam da reprodukujem problem sa ext4 cim skupim malo vremena.
[ Stator @ 23.10.2013. 20:29 ] @
Ne mogu da reprodukujem gresku, stavio sam najnoviji stabilni kernel (3.11) i pustio sam 8 onih skripti da pisu paralelno i tako sam ostavio lap na ~24 sata.

I/O wait je bio oko 90%, HDD je bio 100% zauzet a load je bio oko 13, ali FS nije stucnuo.

Gledao sam sta bi moglo da bude, i ext4 u osnosu na ext3 ima ubacen po default-u "delayed allocation" a posto ova skripta radi vecinu vremena na ~100% popunjenosti diska a ne poziva fsync() manje vise nikada, moze da se desi karambol zbog nedostatka mesta na disku ako system pozove fsync() u trenutku kada je disk 100% pun. Ako skripta trci kao root moze da se desi da popuni onih 5% koji su rezervisani za root-a.

Opet kazem nisam uspeo da reprodukujem, tako da nemam nikakve dokaze da potkrepim ovu teoriju, vec samo spekulisem.
[ pisac @ 26.10.2013. 21:54 ] @
Malo ti je 24 sata, meni je na početku trebalo beše preko 70 sati rada. Sada se to dešava brže, ne znam zašto, razlika je što sada obično startujem samo jednu instancu.

Inače, dobra ideja da startujem skriptu kao ne-root. Ali trenutno imam neke hitnije stvari kojima se bavim pa će ovaj bag(?) sačekati još neku nedelju da mu se posvetim.
[ s!c @ 06.11.2013. 05:43 ] @
Drzi nas updateanima jer se meni slicna stvar dogada na RH 6.3 s razlikom sto sam koristio NOOP scheduler i imam hw raid10 sa SSD-ovima.

Doduse, kod mene stanje slicno tvojem nastaje kada load testam ldap bazu sa visoko postavljenim dirty_ratio i dirty_background_ratio (cca. 70%+).
[ Stator @ 06.11.2013. 09:24 ] @
Da nemas slucajno Red Hat placenu podrsku ? Bilo bi jako zanimljivo da se njima poslje kdump kada se to desi da pogledaju gde je problem.

@ pisac, imam problem da pustim preko 24h da to radi jer se ceo lap jako pregrejava.
[ Branimir Maksimovic @ 15.11.2013. 03:35 ] @
Moguce je da se desava ranije i kasnije zbog toga sto koristis RANDOM, pa se pre ili kasnije uslovi
da zabaguje pogode. Probaj da stavljas fikscno pisanje/ brisanje pa vidi pod kojim uslovima
se ovo desi. Probaj prvo da ne popunis disk a onda sa gotovo punim diskom i slicno.
Ako uspes da reprodukujes mozes prijaviti bug https://www.kernel.org/pub/linux/docs/lkml/reporting-bugs.html
[ pisac @ 24.11.2013. 11:19 ] @
Evo update. Umesto eksperimenata sa mount opcijama, rešio sam da probam da eliminišem hardver kao potencijalni uzrok, i pustio test unutar virtualne (vbox) mašine.

Napravio sam virtualni Slackware14 (64bitni), dodatni virtualni HD od 80GB sa ext4, i pustio test. Test se blokirao posle manje od 24h.

Onda sam napravio virtualni Centos6.4 (32bitni), na njega nakačio isti onaj virtualni HD od 80GB, pustio test... i sve je lepo radilo u narednih 48h pa sam prekinuo test. Sada sam napravio 64bitni Centos6.4, ponovio sve, i evo radi već nešto oko 44h bez problema.

Centos doduše koristi neki 2.6... kernel: "Linux CentOS6.4x64minimal.local 2.6.32-358.el6.x86_64 #1 SMP Fri Feb 22 00:31:26 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux"

Primetio sam da je brzina upisa u virtuelnim mašinama najveća na virtualnom Sleku (oko 85MB/s), pa onda Centos 64bitni (oko 75MB/s), i na kraju Centos 32bitni (oko 60MB/s)

Kada prekinem ovaj Centos test, pustiću i Ubuntu, da vidim šta će tu da se desi.

Nego, da li neko zna da li se (i u čemu) razlikuju default mount opcije između Centos-a i Slackware-a (da nije tu ključna razlika)? Ja nešto nisam upućen u način da saznam sa kojim tačno (default) opcijama je trenutno montirana neka particija.
[ Stator @ 24.11.2013. 11:41 ] @
Najbolje ti je da pogledas sam:

Evo primer za CentOS 6.4:

$ man 8 mount

MOUNT(8) Linux Programmer’s Manual MOUNT(8)
[...]
defaults
Use default options: rw, suid, dev, exec, auto, nouser, async, and relatime.
[...]


Ili mozes sam da pogledas direktno u "/proc" kako je trenutno mount-ovan:

$ grep "/dev/sda2" /proc/mounts
/dev/sda2 / ext4 rw,seclabel,relatime,barrier=1,data=ordered 0 0
[ pisac @ 05.12.2013. 08:29 ] @
Čudno, izgleda da je Slackware14 jedina distribucija na kojoj se dešava ovo. Probao sam (virtuelne) i Ubuntu 10.04, 12.04, pa čak evo već 3 dana ne uspevam da izazovem isto ni na Slackware14.1

Default mount opcije su valjda iste na svima, s tim da nisu uvek prikazane (!). Recimo user_xattr je prikazan jedino na Slack14, ali kada montiram particije na svima ostalima sa -o user_xattr, opet nije prikazana ta opcija, pa pretpostavljam da je to nevidljivi default.

Centos 6.4-64: rw,seclabel,relatime,barrier=1,data=ordered
Slack 14-64 : rw,relatime,user_xattr,barrier=1,data=ordered
Ubuntu 10.04: rw,relatime,barrier=1,data=ordered
Slack 14.1-32: rw,relatime,data=ordered
Slack 14.1-64: rw,relatime,data=ordered

Nije mi samo jasno kako promena kernela na slacku 14 nije rešila problem? Odnosno, šta to tu može biti uzrok a da nema veze sa kernelom?
[ pisac @ 14.01.2014. 15:33 ] @
Slack 14.1 64bitni (3.10.17) se ipak zaglavio, ali posle čitavih 6 dana.
Ubuntu 12.04.3 64bitni (3.8.0-29-generic) se nije zaglavio ni posle 21 dan, pa sam prekinuo.