Dotaz: Start KDE aplikací.

[lertimir]

Lze nějak zjistit, co se přesně děje při startu KDE aplikace?

Mám openSUSE 12.1, distribuční jádro 3.1.9, distribuční KDE 4.7.2, grafika Intel (7.1). Procesor Intel i5 2500K, SSD disk s / a /home. Přes výkoný procesor mě některé aplikace mě dost výrazně startují pomalu někdy se na chvilí kousnou (ale nespadnou, jen se zastaví). Typicky to dělá např Gwenview. Při spuštení z klikáním na obrázek se dokonce i kousne poskakující ikonka u myši. Při spuštění z přikazováho řádku v konzole trvá start cca 10 sec a přitom se zastavují KDE hodiny ve stavovém panelu, přeskají vteřiny, za těch 10 sec jsou třeba jen 2 nebo 3 updaty hodin. Pak aplikace najede a vše jev pořádku.

Je nějaký monitoring, který by zjistil, co se děje? nedělá to jakákoliv aplikace, třeba showfoto najede tak za pul vteřiny a celý digikam do 3 vteřin. ale problémy jsou i jinde např v krusaderu.

Rád bych to i nahlásil, ale netuším, jak to naměřit.

---

---

Odpovědi

[Jack Hokus]

Zdravím,

částečně by na Vaši otázku mohl odpovědět příkaz strace. Přiznávám, že jsem ho nikdy nepoužíval. Snad Vám s počáteční orientací pomůže článek v odkazu

Petr

[lertimir]

Tak jsem zase našel čas se věnoval zkoumání, proč mi gwenview najíždí strašně pomalu a několik výseků z výpisu strace -tt gwenview následuje:

21:07:08.458045 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:08.458065 read(6, "\1 \4\7\0\t\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
21:07:08.458089 read(6, "\314\314\317\377\346\346\351\377\343\343\346\377\353\353\357\377\346\346\346\377\221\221\302\377\317\317\331\377\354\354\355\377"..., 5152) = 5152
21:07:08.458110 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:08.458126 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:08.459008 poll([{fd=6, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=6, revents=POLLOUT}])
21:07:08.459034 writev(6, [{"5 \4\0x\1`\5\275\0\0\0000\0000\0\225\4\5\0y\1`\5x\1`\5&\0\0\0"..., 10696}, {NULL, 0}, {"", 0}], 3) = 10696
21:07:08.460571 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:08.995540 read(6, "\1\3$\7\257\f\0\0\10\377\0\0\177\0\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
21:07:08.995722 read(6, "\1\1\1\0\275\377\0\0\0\0\0\0\1\1\1\0\261\0\0\0\5\0\0\0\1\2\2\0\23\377\0\0"..., 8924) = 8924
21:07:08.995827 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:08.995877 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:08.996002 poll([{fd=6, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=6, revents=POLLOUT}])
21:07:08.996037 writev(6, [{"\21 \2\0\212\0\0\0", 8}, {NULL, 0}, {"", 0}], 3) = 8
21:07:08.996068 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])

Akce v čase 21:07:08.460571 a následují volání je o půl vteřiny později. Další

21:07:09.000235 writev(6, [{"\21 \2\0\220\0\0\0", 8}, {NULL, 0}, {"", 0}], 3) = 8
21:07:09.000256 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:09.020754 read(6, "\1\0008\7\2\0\0\0\10\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 40
21:07:09.020899 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)

ted dvě setiny. Další

21:07:09.049127 writev(6, [{"5\1\4\0\201\1`\5\275\0\0\0 \0 \0007\4\4\0\202\1`\5\201\1`\5\0\0\0\0"..., 2292}, {NULL, 0}, {"", 0}], 3) = 2292
21:07:09.049155 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:09.578065 read(6, "\1\3^\7\257\f\0\0\10\377\0\0\177\0\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
21:07:09.578120 read(6, "\1\1\1\0\275\377\0\0\0\0\0\0\1\1\1\0\261\0\0\0\5\0\0\0\1\2\2\0\23\377\0\0"..., 8924) = 8924

zase půl vteřiny. Další:

21:07:09.584081 writev(6, [{"5\1\4\0\212\1`\5\275\0\0\0 \0 \0007\377\4\0\213\1`\5\212\1`\5\0\0\0\0"..., 272}, {NULL, 0}, {"", 0}], 3) = 272
21:07:09.584105 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:10.120867 read(6, "\1\3\202\7\257\f\0\0\10\377\0\0\177\0\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
21:07:10.120953 read(6, "\1\1\1\0\275\377\0\0\0\0\0\0\1\1\1\0\261\0\0\0\5\0\0\0\1\2\2\0\23\377\0\0"..., 8924) = 8924
21:07:10.121035 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:10.121114 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)

zase půl vteřiny

Jsou i další. Vždy je to stejná posloupnost. Mezi voláním poll a voláním read proběhne obrovský čas, na i5 i když běží pomalu, tak je to na 1,6 GHz a půl vteřiny je hrozně dlouhá doba. Netuší někdo, co to může způsobovat? A kam to případně poslat?

[lertimir]

Nikdo netuší, na čem by to mohlo viset? Měl jsem zato, že sem chodí i lidi kteří programují KDE.

[Ash]

A tušítě s kým si to na tom filedeskriptoru 6 vlastně povídá? Možná by napovědělo něco jako

ls -l /proc/$(pidof gwenview)/fd/6

nebo se podívat do logu strace ještě kousek výš?

[lertimir]

zkusil jsem to projít (tedy vyhledávat string = 6 před touto chybou a vypadá to, že se baví s Xkami.

21:07:08.269474 socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC, 0) = 6
21:07:08.269498 connect(6, {sa_family=AF_FILE, path=@"/tmp/.X11-unix/X0"}, 20) = 0
21:07:08.269564 getpeername(6, {sa_family=AF_FILE, path=@"/tmp/.X11-unix/X0"}, [20]) = 0
21:07:08.269746 munmap(0x7ff247df1000, 4096) = 0
21:07:08.269767 getsockname(6, {sa_family=AF_FILE, NULL}, [2]) = 0
21:07:08.269796 fcntl(6, F_GETFL)       = 0x2 (flags O_RDWR)
21:07:08.269812 fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
21:07:08.269828 fcntl(6, F_SETFD, FD_CLOEXEC) = 0
21:07:08.269849 poll([{fd=6, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=6, revents=POLLOUT}])
21:07:08.269870 writev(6, [{"l\0\v\0\0\0\22\0\20\0\0\0", 12}, {"", 0}, {"MIT-MAGIC-COOKIE-1", 18}, {"\0\0", 2}, {"\21\272eB\375\246\203\32W\343H\\\375j\312\305", 16}, {"", 0}], 6) = 48
21:07:08.269940 read(6, "\1\0\v\0\0\0\363\0", 8) = 8
21:07:08.269960 read(6, "`\350\247\0\0\0`\5\377\377\37\0\0\1\0\0\24\0\377\377\1\7\0\0  \10\377\0\0\0\0"..., 972) = 972
21:07:08.270012 poll([{fd=6, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=6, revents=POLLOUT}])
21:07:08.270030 writev(6, [{"b\0\5\0\f\0\0\0BIG-REQUESTS", 20}], 1) = 20
21:07:08.270074 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:08.270092 read(6, "\1\0\1\0\0\0\0\0\1\217\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 4096) = 32
21:07:08.270121 poll([{fd=6, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=6, revents=POLLOUT}])
21:07:08.270139 writev(6, [{"\217\0\1\0", 4}], 1) = 4
21:07:08.270180 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:08.270198 read(6, "\1\0\2\0\0\0\0\0\377\377?\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 4096) = 32
21:07:08.270229 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:08.270257 poll([{fd=6, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=6, revents=POLLOUT}])
21:07:08.270274 writev(6, [{"7\0\5\0\0\0`\5\275\0\0\0\10\0\0\0\377\377\377\0\24\0\6\0\275\0\0\0\27\0\0\0"..., 44}, {NULL, 0}, {"", 0}], 3) = 44
21:07:08.270328 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:08.270346 read(6, "\1\10\4\0\245\r\0\0\37\0\0\0\0\0\0\0\2246\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
21:07:08.270369 read(6, "SelectionBox.foreground:\t#221f1e"..., 9908) = 9908
21:07:08.270389 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:08.270419 poll([{fd=6, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=6, revents=POLLOUT}])
21:07:08.270436 writev(6, [{"b\0\5\0\t\0`\5", 8}, {"XKEYBOARD", 9}, {"\0\0\0", 3}], 3) = 20
21:07:08.270481 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])
21:07:08.270500 read(6, "\1\0\5\0\0\0\0\0\1\221a\235\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 4096) = 32
21:07:08.270521 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:08.270537 read(6, 0x6b9aa4, 4096) = -1 EAGAIN (Resource temporarily unavailable)
21:07:08.270555 poll([{fd=6, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=6, revents=POLLOUT}])
21:07:08.270572 writev(6, [{"\221\0\2\0\1\0\0\0", 8}, {NULL, 0}, {"", 0}], 3) = 8
21:07:08.270615 poll([{fd=6, events=POLLIN}], 1, -1) = 1 ([{fd=6, revents=POLLIN}])

A pak to pokračuje dále.

[lertimir]

Tedy se souborem od Xek. Adresář /tmp je připojen jako paměť - tmpfs.

>df
Souborový systém          1K-bloků      Užito     Volné Uži% Připojeno do
tmpfs                      4037020       1156   4035864   1% /tmp

[GAZDOWN]

Dobrý den, zkouste spustit

kdebugdialog

a vypnout veškerý ladící výstup.

[lertimir]

Na openSUSE jsem tento problém nevyřešil přes stálé aktualizace. Nicméně upgrade na 12.2 zamrzávání vyřešil. Gwenview v současnosti startuje pod jednu vteřinu.