[kmail2] [Bug 326089] New: accessing mail contents lags for minutes and then sending mail does as well
Martin Steigerwald
Martin at Lichtvoll.de
Wed Oct 16 11:29:00 BST 2013
https://bugs.kde.org/show_bug.cgi?id=326089
Bug ID: 326089
Summary: accessing mail contents lags for minutes and then
sending mail does as well
Classification: Unclassified
Product: kmail2
Version: 4.11.2
Platform: Debian unstable
OS: Linux
Status: UNCONFIRMED
Severity: normal
Priority: NOR
Component: general
Assignee: kdepim-bugs at kde.org
Reporter: Martin at Lichtvoll.de
Note: This bug may be Akonadi related, but since without KMail being started
Akonadi seems to be idling I report it here first.
Today I upgraded kdepim to 4.11 as well after kdelibs/base stuff and kdepimlibs
and akonadi are already updated. Debian Experimental that is.
With kmail 4.11 I get much worse latencies when accessing mails. I get
"retrieving folder contents" for minutes before mail is displayed even when
without kmail being started Akonadi appears to be idle.
CPU wise I usually get something like this:
PID SYSCPU USRCPU VGROW RGROW RDDSK WRDSK ST EXC S CPU CMD
3949 1.40s 3.35s 0K 0K 4K 448K -- - S 48% mysqld
6450 0.22s 3.69s 0K 0K 0K 0K -- - R 40% kmail
3946 1.27s 2.60s 0K 0K 0K 0K -- - S 39% akonadiserver
But what on earth is KMail doing here when it *waits* for Akonadi to retrieve
the mail?
In strace -fF -p pid-of-kmail I get stuff like this
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] ioctl(10, FIONREAD, [255]) = 0
[pid 6097] read(10, "* 81 22 (NAME \"Spam\" MIMETYPE (m"..., 255) = 255
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=3, events=POLLIN}, {fd=8, events=POLLIN}, {fd=7,
events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5,
events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=22,
events=POLLIN}, {fd=24, events=POLLIN}], 10, 20) = 1 ([{fd=10,
revents=POLLIN}])
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] ioctl(10, FIONREAD, [251]) = 0
[pid 6097] read(10, "* 82 22 (NAME \"Unsicher\" MIMETYP"..., 251) = 251
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=3, events=POLLIN}, {fd=8, events=POLLIN}, {fd=7,
events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5,
events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=22,
events=POLLIN}, {fd=24, events=POLLIN}], 10, 19) = 1 ([{fd=10,
revents=POLLIN}])
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] ioctl(10, FIONREAD, [347]) = 0
[pid 6097] read(10, "* 22 10 (NAME \"trash\" MIMETYPE ("..., 347) = 347
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=3, events=POLLIN}, {fd=8, events=POLLIN}, {fd=7,
events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5,
events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=22,
events=POLLIN}, {fd=24, events=POLLIN}], 10, 19) = 1 ([{fd=10,
revents=POLLIN}])
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] ioctl(10, FIONREAD, [394]) = 0
[pid 6097] read(10, "* 10 0 (NAME \"Lokale Ordner\" MIM"..., 394) = 394
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=3, events=POLLIN}, {fd=8, events=POLLIN}, {fd=7,
events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5,
events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=22,
events=POLLIN}, {fd=24, events=POLLIN}], 10, 18) = 1 ([{fd=10,
revents=POLLIN}])
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] ioctl(10, FIONREAD, [24]) = 0
[pid 6097] read(10, "1351 OK List completed\r\n", 24) = 24
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=3, events=POLLIN}, {fd=8, events=POLLIN}, {fd=7,
events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5,
events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=22,
events=POLLIN}, {fd=24, events=POLLIN}], 10, 0) = 1 ([{fd=3, revents=POLLIN}])
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=3, events=POLLIN}, {fd=8, events=POLLIN}, {fd=7,
events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5,
events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=22,
events=POLLIN}, {fd=24, events=POLLIN}], 10, 0) = 1 ([{fd=3, revents=POLLIN}])
[pid 6097] read(3, "\t\0\0\0\0\0\0\0", 16) = 8
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] sendmsg(5, {msg_name(0)=NULL,
msg_iov(2)=[{"l\1\1\1`\0\0\0\335\27\0\0\213\0\0\0\1\1o\0\v\0\0\0/jobtrac"...,
160}, {"\20\0\0\0kmail2-542439653\0\0\0\0\7\0\0\0005484"..., 96}],
msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 256
[pid 6097] sendmsg(5, {msg_name(0)=NULL,
msg_iov(2)=[{"l\1\1\1`\0\0\0\336\27\0\0\213\0\0\0\1\1o\0\v\0\0\0/jobtrac"...,
160}, {"\20\0\0\0kmail2-542439653\0\0\0\0\7\0\0\00053c5"..., 96}],
msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 256
[pid 6097] sendmsg(5, {msg_name(0)=NULL,
msg_iov(2)=[{"l\1\1\1\21\0\0\0\337\27\0\0\210\0\0\0\1\1o\0\v\0\0\0/jobtrac"...,
152}, {"\7\0\0\000545e230\0\0\0\0\0\0", 17}], msg_controllen=0, msg_flags=0},
MSG_NOSIGNAL) = 169
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=3, events=POLLIN}, {fd=8, events=POLLIN}, {fd=7,
events=POLLIN}, {fd=9, events=POLLIN}, {fd=10, events=POLLIN}, {fd=5,
events=POLLIN}, {fd=13, events=POLLIN}, {fd=15, events=POLLIN}, {fd=22,
events=POLLIN}, {fd=24, events=POLLIN}, {fd=10, events=POLLOUT}], 11, 0) = 2
([{fd=3, revents=POLLIN}, {fd=10, revents=POLLOUT}])
[pid 6097] read(3, "\5\0\0\0\0\0\0\0", 16) = 8
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] sendmsg(5, {msg_name(0)=NULL,
msg_iov(2)=[{"l\1\1\1\f\0\0\0\340\27\0\0\207\0\0\0\1\1o\0\v\0\0\0/jobtrac"...,
152}, {"\7\0\0\000545e110\0", 12}], msg_controllen=0, msg_flags=0},
MSG_NOSIGNAL) = 164
[pid 6097] poll([{fd=7, events=POLLIN|POLLOUT}], 1, 4294967295) = 1 ([{fd=7,
revents=POLLOUT}])
[pid 6097] writev(7, [{"+\3\1\0", 4}, {NULL, 0}, {"", 0}], 3) = 4
[pid 6097] poll([{fd=7, events=POLLIN}], 1, 4294967295) = 1 ([{fd=7,
revents=POLLIN}])
[pid 6097] recvfrom(7,
"\1\1IK\0\0\0\0\32\0\0\5\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 4096, 0,
NULL, NULL) = 32
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=7, events=POLLIN|POLLOUT}], 1, 4294967295) = 1 ([{fd=7,
revents=POLLOUT}])
[pid 6097] writev(7, [{"&\3\2\0\241\0\0\0", 8}, {NULL, 0}, {"", 0}], 3) = 8
[pid 6097] poll([{fd=7, events=POLLIN}], 1, 4294967295) = 1 ([{fd=7,
revents=POLLIN}])
[pid 6097] recvfrom(7,
"\1\1JK\0\0\0\0\241\0\0\0h\3\300\1\374\0\256\3\374\0\256\3\4\0\0\0\0\0\0\0",
4096, 0, NULL, NULL) = 32
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] poll([{fd=7, events=POLLIN|POLLOUT}], 1, 4294967295) = 1 ([{fd=7,
revents=POLLOUT}])
[pid 6097] writev(7, [{"(\3\4\0\241\0\0\0U\0\340\6\374\0\256\3", 16}, {NULL,
0}, {"", 0}], 3) = 16
[pid 6097] poll([{fd=7, events=POLLIN}], 1, 4294967295) = 1 ([{fd=7,
revents=POLLIN}])
[pid 6097] recvfrom(7,
"\1\1KK\0\0\0\0\0\0\0\0\374\0O\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 4096, 0,
NULL, NULL) = 32
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] recvfrom(7, 0x2469ca4, 4096, 0, 0, 0) = -1 EAGAIN (Resource
temporarily unavailable)
[pid 6097] write(3, "\1\0\0\0\0\0\0\0", 8) = 8
So basically KMail seems to be polling something endlessly.
Whats going on there?
Its 1, in words: one, mail I try to access in kmail.
While this activity happens I can still change folders and get updates mail
lists quickly, it is just accessing the mail contents that is so slow that
KMail is currently unusable for me and I am considering downgrading to 4.10
again.
According to akonadiconsole Akonadi is basically idling during that time which
is basically a lie above atop CPU usage information above.
I used up 10 minutes or so in writing this mail and I still get:
PID SYSCPU USRCPU VGROW RGROW RDDSK WRDSK ST EXC S CPU CMD 1/3
3949 1.45s 3.44s 0K 0K 4K 480K -- - S 50% mysqld
3946 1.31s 2.65s 0K 0K 0K 0K -- - S 40% akonadiserver
6450 0.21s 3.60s 296K 252K 0K 0K -- - S 39% kmail
I am still trying to send this as mail out to kdepim-users and it just
*stalls*. This is unusable slow and I think I will have to downgrade.
Reproducible: Always
Steps to Reproduce:
1. have some POP3 accounts with lots of mails.
2. start kmail
3. access a mail
4. access another mail
5. wait
6. wait
7. wait
…
Actual Results:
Unusable long lags.
Expected Results:
Snappy response.
martin at merkaba:~> apt-show-versions | egrep
"akonadi|kdepim|kmail|kdelibs|libqtgui|crm114|mysql"
akonadi-backend-mysql:all/experimental 1.10.2-1 uptodate
akonadi-backend-sqlite:amd64/sid 1.9.2-2+b1 uptodate
akonadi-server:amd64/experimental 1.10.2-1 uptodate
akonadiconsole:amd64/experimental 4:4.11.2-1 uptodate
crm114:amd64/sid 20100106-3 uptodate
kdelibs-bin:amd64/experimental 4:4.11.2-1 uptodate
kdelibs5-data:all/experimental 4:4.11.2-1 uptodate
kdelibs5-plugins:amd64/experimental 4:4.11.2-1 uptodate
kdepim:all/experimental 4:4.11.2-1 uptodate
kdepim-kresources:amd64/experimental 4:4.11.2-1 uptodate
kdepim-runtime:amd64/experimental 4:4.11.2-2 uptodate
kdepimlibs-kio-plugins:amd64/experimental 4:4.11.2-2 uptodate
kmail:amd64/experimental 4:4.11.2-1 uptodate
libakonadi-calendar4:amd64/experimental 4:4.11.2-2 uptodate
libakonadi-contact4:amd64/experimental 4:4.11.2-2 uptodate
libakonadi-kabc4:amd64/experimental 4:4.11.2-2 uptodate
libakonadi-kcal4:amd64/experimental 4:4.11.2-2 uptodate
libakonadi-kde4:amd64/experimental 4:4.11.2-2 uptodate
libakonadi-kmime4:amd64/experimental 4:4.11.2-2 uptodate
libakonadi-notes4:amd64/experimental 4:4.11.2-2 uptodate
libakonadiprotocolinternals1:amd64/experimental 1.10.2-1 uptodate
libdbd-mysql-perl:amd64/sid 4.024-1 uptodate
libkdepim4:amd64/experimental 4:4.11.2-1 uptodate
libkdepimdbusinterfaces4:amd64/experimental 4:4.11.2-1 uptodate
libmysqlclient-dev:amd64/sid 5.5.33+dfsg-1 uptodate
libmysqlclient18:amd64/sid 5.5.33+dfsg-1 uptodate
libqt4-sql-mysql:amd64/sid 4:4.8.5+git121-g2a9ea11+dfsg1-2 uptodate
libqtgui4:amd64/sid 4:4.8.5+git121-g2a9ea11+dfsg1-2 uptodate
mysql-client:all/sid 5.5.33+dfsg-1 uptodate
mysql-client-5.5:amd64/sid 5.5.33+dfsg-1 uptodate
mysql-common:all/sid 5.5.33+dfsg-1 uptodate
mysql-server-core-5.5:amd64/sid 5.5.33+dfsg-1 uptodate
python-mysqldb:amd64/sid 1.2.3-2 uptodate
--
You are receiving this mail because:
You are the assignee for the bug.
More information about the Kdepim-bugs
mailing list