<html><head><meta http-equiv="Content-Type" content="text/html; charset=UTF-8" /></head><body style='font-size: 10pt; font-family: Verdana,Geneva,sans-serif'>
<p>On 2015-09-09 11:56, Paul Bronson wrote:</p>
<blockquote type="cite" style="padding: 0 0.4em; border-left: #1010ff 2px solid; margin: 0"><!-- html ignored --><!-- head ignored --><!-- meta ignored -->
<div dir="ltr">Hi guys,
<div> </div>
<div>For those of you who are not CC'ed on my bug (<a href="https://issues.kolab.org/show_bug.cgi?id=5219">https://issues.kolab.org/show_bug.cgi?id=5219</a>) here's what I've came up with regarding this plugin slow down:</div>
<div> </div>
<div>
<div>Okay, so I tried putting the preview pane down.. Opening an actual message I got the following for a SINGLE message:</div>
<div> </div>
<div>Sep 8 19:38:58 es1 imap[25729]: starttls: TLSv1 with cipher ECDHE-RSA-AES256-SHA (256/256 bits new) no authentication</div>
<div>Sep 8 19:38:58 es1 imap[25729]: login: localhost [::1] <a href="mailto:jdoe@domain.info">jdoe@domain.info</a> PLAIN+TLS User logged in SESSIONID=<es1.domain.com-25729-1441755538-1-17808047228044173595></div>
<div>Sep 8 19:38:59 es1 imap[25729]: USAGE <a href="mailto:jdoe@domain.info">jdoe@domain.info</a> user: 0.017997 sys: 0.017997</div>
<div>Sep 8 19:39:00 es1 imap[25714]: starttls: TLSv1 with cipher ECDHE-RSA-AES256-SHA (256/256 bits new) no authentication</div>
<div>Sep 8 19:39:00 es1 imap[25760]: starttls: TLSv1 with cipher ECDHE-RSA-AES256-SHA (256/256 bits new) no authentication</div>
<div>Sep 8 19:39:00 es1 imap[25714]: login: localhost [::1] <a href="mailto:jdoe@domain.info">jdoe@domain.info</a> PLAIN+TLS User logged in SESSIONID=<es1.domain.com-25714-1441755540-1-1643183847780605755></div>
<div>Sep 8 19:39:00 es1 imap[25714]: USAGE <a href="mailto:jdoe@domain.info">jdoe@domain.info</a> user: 0.003999 sys: 0.003000</div>
<div>Sep 8 19:39:00 es1 imap[25760]: login: localhost [::1] <a href="mailto:jdoe@domain.info">jdoe@domain.info</a> PLAIN+TLS User logged in SESSIONID=<es1.domain.com-25760-1441755540-1-3316720433793663553></div>
<div>Sep 8 19:39:00 es1 imap[25760]: USAGE <a href="mailto:jdoe@domain.info">jdoe@domain.info</a> user: 0.008998 sys: 0.005000</div>
<div> </div>
<div>Back to original problem of just going through messages Now, just turning on SQL debug, here's all the queries running just simply selecting a message to be shown in the preview pane:</div>
<div> </div>
<div>[08-Sep-2015 19:46:15,000000 -0400]: <840cvre1> [1] SELECT `vars`, `ip`, `changed`, now() AS ts FROM `session` WHERE `sess_id` = '840cvre1hecdhc9qnkgkfk73t0';</div>
<div>[08-Sep-2015 19:46:15,000000 -0400]: <840cvre1> [2] SELECT * FROM `users` WHERE `user_id` = '4';</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [3] SELECT `folder_id`, `synclock`, `ctag`, `changed`, `objectcount` FROM `kolab_folders` WHERE `resource` = 'imap://tperson%40domain.info@localhost/Configuration';</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [4] SELECT COUNT(*) AS `numrows` FROM `kolab_cache_configuration` WHERE `folder_id` = '46';</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [5] SELECT * FROM `kolab_cache_configuration` WHERE `folder_id` = '46' AND `type` = 'relation' AND `tags` LIKE '% category:tag %' LIMIT 100;</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [6] SELECT `flags`, `data` FROM `cache_messages` WHERE `user_id` = '4' AND `mailbox` = 'INBOX' AND `uid` = '1';</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [7] SELECT * FROM `kolab_cache_configuration` WHERE `folder_id` = '46' AND `type` = 'relation' AND `tags` LIKE '% category:generic %' AND `words` LIKE '% <<a href="mailto:0d41a56b9d73f705c587eda81c950ae4@domain.com">0d41a56b9d73f705c587eda81c950ae4@domain.com</a>> %' LIMIT 100;</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [8] SELECT `folder_id`, `synclock`, `ctag`, `changed`, `objectcount` FROM `kolab_folders` WHERE `resource` = 'imap://tperson%40domain.info@localhost/Contacts';</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [9] SELECT COUNT(*) AS `numrows` FROM `kolab_cache_contact` WHERE `folder_id` = '47';</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [10] SELECT COUNT(*) AS `numrows` FROM `kolab_cache_contact` WHERE `folder_id` = '47' AND `words` LIKE '% <a href="mailto:jdoe@domain.com">jdoe@domain.com</a> %';</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [11] SELECT * FROM `kolab_cache_contact` WHERE `folder_id` = '47' AND `words` LIKE '% <a href="mailto:jdoe@domain.com">jdoe@domain.com</a> %';</div>
<div>[08-Sep-2015 19:46:16,000000 -0400]: <840cvre1> [12] SELECT * FROM `kolab_cache_configuration` WHERE `folder_id` = '46' AND `type` = 'relation' AND `tags` LIKE '% category:tag %' LIMIT 100;</div>
<div>[08-Sep-2015 19:46:17,000000 -0400]: <840cvre1> [13] SELECT `vars`, `ip`, `changed`, now() AS ts FROM `session` WHERE `sess_id` = '840cvre1hecdhc9qnkgkfk73t0';</div>
<div>[08-Sep-2015 19:46:19,000000 -0400]: <840cvre1> [1] SELECT `vars`, `ip`, `changed`, now() AS ts FROM `session` WHERE `sess_id` = '840cvre1hecdhc9qnkgkfk73t0';</div>
<div>[08-Sep-2015 19:46:19,000000 -0400]: <840cvre1> [2] SELECT * FROM `users` WHERE `user_id` = '4';</div>
<div>[08-Sep-2015 19:46:19,000000 -0400]: <840cvre1> [3] SELECT `data`, `valid` FROM `cache_index` WHERE `user_id` = '4' AND `mailbox` = 'INBOX';</div>
<div>[08-Sep-2015 19:46:21,000000 -0400]: <840cvre1> [4] SELECT `vars`, `ip`, `changed`, now() AS ts FROM `session` WHERE `sess_id` = '840cvre1hecdhc9qnkgkfk73t0';</div>
</div>
<div> </div>
<div>There's a lot of cache tables it looks like... But why is IMAP being queried so heavily? And yes, there is stuff in these tables.</div>
<div> </div>
</div>
<div class="gmail_extra"><br />
<div class="gmail_quote">On Tue, Sep 8, 2015 at 5:51 PM, <span><<a href="mailto:signaldeveloper@gmail.com">signaldeveloper@gmail.com</a>></span> wrote:<br />
<blockquote class="gmail_quote" style="margin: 0 0 0 .8ex; border-left: 1px #ccc solid; padding-left: 1ex;">Hi Christian,<br /><br /> I basically installed memcache and just changed 'DB' to 'memcache' in the kolab config. This seemed to give me a small boost but I think I'll feel the better boost when I start piling on users.<br /><br /> I for some reason couldn't get memcache to work with "session_storage" though, it just gives me a white screen. Let me know if you need more in depth directions!<br /><br /> If anyone has varnish setup please let me know if love to know how to get that working with roundcube!<br /><span class="HOEnZb"><span style="color: #888888;"><br /><br /><br /> - Paul<br /></span></span>
<div class="HOEnZb">
<div class="h5"><br /><br /><br /> > On Sep 8, 2015, at 12:09 PM, Christian Hügel <<a href="mailto:christian.huegel@stonebyte.de">christian.huegel@stonebyte.de</a>> wrote:<br /> ><br /> > OK, i got you right now :) You mentioned a performance boost using<br /> > memcached. Can you point me a documentation enabling this?<br /> > Thanks<br /> ><br /> >> Am 08.09.2015 um 17:54 schrieb <a href="mailto:signaldeveloper@gmail.com">signaldeveloper@gmail.com</a>:<br /> >> Christian,<br /> >><br /> >> Obviously. This is meant more as a bug test case not as a fix.<br /> >><br /> >><br /> >><br /> >>> On Sep 8, 2015, at 11:46 AM, Christian Hügel <<a href="mailto:christian.huegel@stonebyte.de">christian.huegel@stonebyte.de</a>> wrote:<br /> >>><br /> >>> I also have a major performance problem although with kolab 3.2 but I do<br /> >>> not see the point in deactivating those plugins; it would´ t be a kolab<br /> >>> server anymore instead just an ordinary imap server. So this workaround<br /> >>> is a "no go"<br /> >>><br /> >>> Cheers,<br /> >>><br /> >>> Christian<br /> >>><br /> >>>> Am 07.09.2015 um 20:55 schrieb Paul Bronson:<br /> >>>> Hi guys, (happy labor day!)<br /> >>>><br /> >>>> As you've probably seen me asking a thousand questions about slowness<br /> >>>> for my brand new kolab 3.4, here's what my few weeks of research has<br /> >>>> come up with... And hopefully this will work for all of you as well, or<br /> >>>> something you can try and replicate on your end:<br /> >>>><br /> >>>> A few kolab plugins are initiating an imap connection every time the<br /> >>>> user simply tries to read a message. Those plugins are:<br /> >>>><br /> >>>> kolab_addressbook<br /> >>>> kolab_notes<br /> >>>> kolab_tags<br /> >>>> tasklist<br /> >>>><br /> >>>> If you disable ALL (not one) of these plugins, watch how magically fast<br /> >>>> clicking on a message is. You will also notice logs in your<br /> >>>> var/log/maillog such as this disappear:<br /> >>>><br /> >>>><br /> >>>> Sep 7 13:59:55 es1 imap[18657]: USAGE <a href="mailto:tperson@domain.info">tperson@domain.info</a><br /> >>>> <mailto:<a href="mailto:tperson@domain.info">tperson@domain.info</a>>user: 0.004000 sys: 0.007999<br /> >>>><br /> >>>> Sep 7 14:00:55 es1 imap[18657]: login: localhost [::1] <a href="mailto:tperson@domain.info">tperson@domain.info</a> <mailto:<a href="mailto:tperson@domain.info">tperson@domain.info</a>> PLAIN User logged in SESSIONID=<es1.domain.com-18657-1441648854-1-17261199637593060143><br /> >>>><br /> >>>> These above log entries will however happen when you go to different<br /> >>>> folders, but simply just single clicking a message to see it on the<br /> >>>> preview pane will no longer log the entry.<br /> >>>><br /> >>>><br /> >>>> I have also seen a HUGE improvement from memcache as well. (now that<br /> >>>> instead of opening a new connection, it can now actually check against<br /> >>>> memcache for a cache'd version) I also went to vast lands to try to make<br /> >>>> cyrus faster thinking that was the problem, but I think this was the key!<br /> >>>><br /> >>>><br /> >>>> I've logged a bug for this:<br /> >>>><br /> >>>> <a href="https://issues.kolab.org/show_bug.cgi?id=5219">https://issues.kolab.org/show_bug.cgi?id=5219</a><br /> >>>><br /> >>>><br /> >>>> Hopefully this will be an easy fix for the team!<br /> >>>><br /> >>>><br /> >>>></div>
<div class="h5">I do not see that level of login activity.</div>
<div class="h5"> </div>
<div class="h5">If I select an email that I have not previously selected within the cache TTL then I see two logins. If I select an email within the cache TTL then I see one login.</div>
<div class="h5"> </div>
<div class="h5">Doing a data capture of the latter situation I get:</div>
<div class="h5"> </div>
<div class="h5">
<pre class="wiki">[root@kolab04 etc]# tshark -i lo port 143
59.229818 ::1 -> ::1 TCP 94 57268 > imap [SYN] Seq=0 Win=65476 Len=0 MSS=65476 SACK_PERM=1 TSval=1846400895 TSecr=0 WS=128
59.229856 ::1 -> ::1 TCP 94 imap > 57268 [SYN, ACK] Seq=0 Ack=1 Win=65464 Len=0 MSS=65476 SACK_PERM=1 TSval=1846400895 TSecr=1846400895 WS=128
59.229878 ::1 -> ::1 TCP 86 57268 > imap [ACK] Seq=1 Ack=1 Win=65536 Len=0 TSval=1846400895 TSecr=1846400895
59.230788 ::1 -> ::1 IMAP 259 Response: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE STARTTLS AUTH=LOGIN AUTH=PLAIN SASL-IR] kolab04.devnull.net.nz Cyrus IMAP git2.5+0-Kolab-2.5-108.1.el6.kolab_3.4 server ready
59.230820 ::1 -> ::1 TCP 86 57268 > imap [ACK] Seq=1 Ack=174 Win=66560 Len=0 TSval=1846400896 TSecr=1846400896
59.231018 ::1 -> ::1 IMAP 165 Request: A0001 AUTHENTICATE PLAIN AG1pa2UuYnJhZHlAZGV2bnVsbC5uZXQubnoASnVtYm8tLTc0NyE=
59.231034 ::1 -> ::1 TCP 86 imap > 57268 [ACK] Seq=174 Ack=80 Win=65536 Len=0 TSval=1846400896 TSecr=1846400896
59.256049 ::1 -> ::1 IMAP 760 Response: A0001 OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] Success (no protection) SESSIONID=<kolab04.devnull.net.nz-7682-1441704301-1-10394088694658571917>
59.257515 ::1 -> ::1 IMAP 114 Request: A0002 SELECT Configuration
59.258149 ::1 -> ::1 IMAP 406 Response: * 0 EXISTS
59.297563 ::1 -> ::1 TCP 86 57268 > imap [ACK] Seq=108 Ack=1168 Win=69248 Len=0 TSval=1846400963 TSecr=1846400923
59.448120 ::1 -> ::1 IMAP 100 Request: A0003 LOGOUT
59.448412 ::1 -> ::1 IMAP 129 Response: * BYE LOGOUT received
59.448438 ::1 -> ::1 TCP 86 57268 > imap [ACK] Seq=122 Ack=1211 Win=69248 Len=0 TSval=1846401114 TSecr=1846401113
59.448501 ::1 -> ::1 TCP 86 imap > 57268 [FIN, ACK] Seq=1211 Ack=122 Win=65536 Len=0 TSval=1846401114 TSecr=1846401114
59.448556 ::1 -> ::1 TCP 86 57268 > imap [FIN, ACK] Seq=122 Ack=1212 Win=69248 Len=0 TSval=1846401114 TSecr=1846401114
59.448568 ::1 -> ::1 TCP 86 imap > 57268 [ACK] Seq=1212 Ack=123 Win=65536 Len=0 TSval=1846401114 TSecr=1846401114</pre>
<pre class="wiki">I see the "SELECT Configuration" for every email selected. I think that the Configuration folder is where tags are kept? So I am assuming that this is a check for tags for every selection? Should this be cached?<br /><br />Even with the level of logins you are seeing, which I agree with you doesn't seem right, I would not expect to see the level of poor performance that you have indicated. In a previous thread I think that you said 5 seconds for an email? I think that you may well have other non cache issues as well.<br /><br />Have you also looked at taking measures to speed up the IMAP connections. Two that have made a difference for me are adding "<span>$config['imap_auth_type'] = 'PLAIN';" to /etc/roundcube/config.inc.php and not running TLS for localhost IMAP connections.<br /></span><br />Regards<br /><br />Mike<br /><br /><br /></pre>
</div>
</div>
</blockquote>
</div>
</div>
</blockquote>
<div> </div>
</body></html>