Cyrus gurus - can you help us diagnose the IMAP debug below that I gave and help us understand the slow down. I am no imap pro, but the imap_debug below seems to show a lot of in-and-out's for a single message click. Again this is roundcube, centos 6, kolab 3.4, cyrus version:
name : Cyrus IMAPD
version : git2.5+0-Kolab-2.5-108.1.el6.kolab_3.4
vendor : Project Cyrus
support-url: http://www.cyrusimap.org
os : Linux
os-version : 2.6.32-042stab108.7
environment: Built w/Cyrus SASL 2.1.23
Running w/Cyrus SASL 2.1.23
Built w/OpenSSL 1.0.1e-fips 11 Feb 2013
Running w/OpenSSL 1.0.1e-fips 11 Feb 2013
Built w/zlib 1.2.3
Running w/zlib 1.2.3
CMU Sieve 2.4
TCP Wrappers
NET-SNMP
mmap = shared
lock = fcntl
nonblock = fcntl
idle = idled
See below for all other comments. Again, this is all regarding bug: https://issues.kolab.org/show_bug.cgi?id=5219
On Sat, Sep 12, 2015 at 7:39 PM, Brady, Mike <mike.brady@xxxxxxxxxxxxxx> wrote:
On 2015-09-11 14:31, signaldeveloper@xxxxxxxxx wrote:
Mike,If I disable a bunch of the plugins, all of the constant IMAP logins go away as described in my bug: https://issues.kolab.org/show_bug.cgi?id=5219Yes I have looked at the bug and as I have stated I do not see this behaviour, but that wasn't what I asked anyway.You have stated that IMAP logins are slow and implied that that there are those on the Cyrus IMAP mailing list who also think that they are slow. I take this to mean that an individual login is slow. That there are more logins than you think there should be is a different (and perfectly valid) question.So I will ask again, with some slightly different words to try an make my question clearer. How has it been determined that an individual IMAP login is slow. Slow being a subjective term I am looking for number(s) that we can objectively compare here. Are the user and sys values on the USAGE line in the logs the login timings? What do the Cyrus guys think that these numbers should be in order for them not to be considered slow?
Mike - not exactly sure what those mean on the line, I will consult with them in a few minutes. You know, I'm not even sure it's the SPEED of cyrus as much as the LOAD it gets put on it from the multiple check in's and etc etc. I've posted my IMAP debug on the bug and I'll post it here too:
[12-Sep-2015 19:53:31,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE STARTTLS LOGINDISABLED] es1.domain.com Cyrus IMAP git2.5+0-Kolab-2.5-108.1.el6.kolab_3.4 server ready
[12-Sep-2015 19:53:31,000000 -0400]: <mp2vnqo7> [4F50] C: A0001 STARTTLS
[12-Sep-2015 19:53:31,000000 -0400]: <mp2vnqo7> [4F50] S: A0001 OK Begin TLS negotiation now
[12-Sep-2015 19:53:31,000000 -0400]: <mp2vnqo7> [4F50] C: A0002 CAPABILITY
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * 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 AUTH=LOGIN AUTH=PLAIN SASL-IR COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0002 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0003 ID ("name" "Roundcube" "version" "1.1.2" "php" "5.3.3" "os" "Linux" "command" "/webmail/8d61c34e132a834f/?_task=mail&_action=preview&_uid=11&_mbox=INBOX&_framed=1&_caps=pdf%3D1%2Cflash%3D1%2Ctif%3D0")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * ID ("name" "Cyrus IMAPD" "version" "git2.5+0-Kolab-2.5-108.1.el6.kolab_3.4 " "vendor" "Project Cyrus" "support-url" "http://www.cyrusimap.org" "os" "Linux" "os-version" "2.6.32-042stab108.7" "environment" "Built w/Cyrus SASL 2.1.23; Running w/Cyrus SASL 2.1.23; Built w/OpenSSL 1.0.1e-fips 11 Feb 2013; Running w/OpenSSL 1.0.1e-fips 11 Feb 2013; Built w/zlib 1.2.3; Running w/zlib 1.2.3; CMU Sieve 2.4; TCP Wrappers; NET-SNMP; mmap = shared; lock = fcntl; nonblock = fcntl; idle = idled")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0003 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0004 AUTHENTICATE PLAIN ****** [57]
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0004 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 (tls protection) SESSIONID=<es1.domain.com-11851-1442102011-1-8161494193998890916>
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0005 GETMETADATA "*" (/private/vendor/kolab/folder-type /shared/vendor/kolab/folder-type)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA INBOX (/shared/vendor/kolab/folder-type "mail" /private/vendor/kolab/folder-type "mail.inbox")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Archive (/private/vendor/kolab/folder-type NIL /shared/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Calendar (/shared/vendor/kolab/folder-type "event" /private/vendor/kolab/folder-type "event.default")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA "Calendar/Personal Calendar" (/shared/vendor/kolab/folder-type "event" /private/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Configuration (/shared/vendor/kolab/folder-type "configuration.default" /private/vendor/kolab/folder-type "configuration.default")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Contacts (/shared/vendor/kolab/folder-type "contact" /private/vendor/kolab/folder-type "contact.default")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA "Contacts/Personal Contacts" (/shared/vendor/kolab/folder-type "contact" /private/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Drafts (/private/vendor/kolab/folder-type "mail.drafts" /shared/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Files (/private/vendor/kolab/folder-type "file.default" /shared/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Freebusy (/shared/vendor/kolab/folder-type "freebusy" /private/vendor/kolab/folder-type "freebusy.default")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Journal (/shared/vendor/kolab/folder-type "journal" /private/vendor/kolab/folder-type "journal.default")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Notes (/shared/vendor/kolab/folder-type "note" /private/vendor/kolab/folder-type "note.default")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Sent (/private/vendor/kolab/folder-type "mail.sentitems" /shared/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Spam (/private/vendor/kolab/folder-type "mail.junkemail" /shared/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Tasks (/shared/vendor/kolab/folder-type "task" /private/vendor/kolab/folder-type "task.default")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Trash (/private/vendor/kolab/folder-type "mail.wastebasket" /shared/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0005 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0006 LIST "" Configuration
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Configuration
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0006 OK Completed (0.000 secs 2 calls)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0007 MYRIGHTS Configuration
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * MYRIGHTS Configuration lrswipkxtecdan
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0007 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0008 SELECT Configuration
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * 0 EXISTS
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * 0 RECENT
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [UIDVALIDITY 1441467299] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [UIDNEXT 1] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [HIGHESTMODSEQ 1] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [URLMECH INTERNAL] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [ANNOTATIONS 65536] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0008 OK [READ-WRITE] Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0009 LSUB "" "*"
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB (\Noinferiors) "/" INBOX
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Archive
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB (\HasChildren) "/" Calendar
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" "Calendar/Personal Calendar"
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Configuration
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB (\HasChildren) "/" Contacts
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" "Contacts/Personal Contacts"
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Drafts
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Files
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Freebusy
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Journal
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Notes
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Sent
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Spam
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Tasks
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LSUB () "/" Trash
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0009 OK Completed (0.000 secs 16 calls)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0010 LIST "" "*"
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\Noinferiors \HasNoChildren) "/" INBOX
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Archive
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasChildren) "/" Calendar
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" "Calendar/Personal Calendar"
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Configuration
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasChildren) "/" Contacts
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" "Contacts/Personal Contacts"
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Drafts
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Files
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Freebusy
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Journal
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Notes
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Sent
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Spam
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Tasks
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * LIST (\HasNoChildren) "/" Trash
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0010 OK Completed (0.000 secs 17 calls)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0011 GETMETADATA Archive (/private/vendor/kolab/folder-type /shared/vendor/kolab/folder-type)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Archive (/private/vendor/kolab/folder-type NIL /shared/vendor/kolab/folder-type NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0011 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0012 MYRIGHTS Tasks
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * MYRIGHTS Tasks lrswipkxtecdan
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0012 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0013 GETMETADATA Tasks (/private/vendor/kolab/displayname /shared/vendor/kolab/displayname)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Tasks (/private/vendor/kolab/displayname NIL /shared/vendor/kolab/displayname NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0013 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0014 GETMETADATA Tasks (/private/vendor/kolab/color /shared/vendor/kolab/color)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Tasks (/private/vendor/kolab/color NIL /shared/vendor/kolab/color NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0014 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0015 MYRIGHTS Contacts
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * MYRIGHTS Contacts lrswipkxtecdan
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0015 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0016 MYRIGHTS "Contacts/Personal Contacts"
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * MYRIGHTS "Contacts/Personal Contacts" lrswipkxtecdan
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0016 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0017 GETMETADATA Contacts (/private/vendor/kolab/displayname /shared/vendor/kolab/displayname)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Contacts (/private/vendor/kolab/displayname NIL /shared/vendor/kolab/displayname NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0017 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0018 GETMETADATA "Contacts/Personal Contacts" (/private/vendor/kolab/displayname /shared/vendor/kolab/displayname)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA "Contacts/Personal Contacts" (/private/vendor/kolab/displayname NIL /shared/vendor/kolab/displayname NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0018 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0019 GETMETADATA Contacts (/private/vendor/kolab/uniqueid /shared/vendor/cmu/cyrus-imapd/uniqueid /shared/vendor/kolab/uniqueid)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Contacts (/private/vendor/kolab/uniqueid NIL /shared/vendor/kolab/uniqueid NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA Contacts (/shared/vendor/cmu/cyrus-imapd/uniqueid "e6846254-d573-4d66-a14e-37ecfb5027a3")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0019 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0020 GETMETADATA "Contacts/Personal Contacts" (/private/vendor/kolab/uniqueid /shared/vendor/cmu/cyrus-imapd/uniqueid /shared/vendor/kolab/uniqueid)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA "Contacts/Personal Contacts" (/private/vendor/kolab/uniqueid NIL /shared/vendor/kolab/uniqueid NIL)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * METADATA "Contacts/Personal Contacts" (/shared/vendor/cmu/cyrus-imapd/uniqueid "6b53dbe3-cc85-4118-b863-2f3cca2eb0c5")
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0020 OK Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0021 SELECT Contacts
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [CLOSED] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * 1 EXISTS
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * 0 RECENT
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [UNSEEN 1] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [UIDVALIDITY 1441467295] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [UIDNEXT 2] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [HIGHESTMODSEQ 2] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [URLMECH INTERNAL] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * OK [ANNOTATIONS 65536] Ok
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0021 OK [READ-WRITE] Completed
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] C: A0022 LOGOUT
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: * BYE LOGOUT received
[12-Sep-2015 19:53:32,000000 -0400]: <mp2vnqo7> [4F50] S: A0022 OK Completed
It's odd because only (not in front of me right now) a few of the actual kolab plugins check in EVERY message select. If you disable them, the system runs super fast. I watch as the plugin check in on SQL but they also check in with IMAP. I'm not sure what else to do but the Cyrus guys are telling me kolab may have compiled their SASL not too smart.What is it that they think is wrong exactly or at least in what area do they think that there is an issue?
They're telling me the multiple check-in's with IMAP is costly. I am not a imap dev, sorry - didn't get much more than that. Another guy suggested cache wasn't working right, but I watch things update everywhere they're supposed to regarding cache (especially in the kolab cache mysql table) so that looks well. The Mysql log shows a ton going on for a SINGLE message click. Look at the mysql logs I provided.
At this point I am hoping to hear something from these guys about what's going on.Mike - have you tried following my steps in the bug? You may see a difference just disabling the few plugins (testing obviously, not permanent). Just following the steps I provided and see what happens.I have not tried this because, as I have said before, I do not see this behaviour at all.
You (as many others) may not think your install is slow, but I am telling you, just go in, disable the plugins I have explained, and give it a shot. Watch your message load increase by 10x. Christian (CC'ed) tried this, and it worked awesome for him as well. Of course this isn't perfect/permanent and you can simply re-enable the plugins, nothing will happen to your install. I would at least try it and you'll see what I am talking about. Maybe you just aren't used to the fast actions on mail servers like I am. Give it a shot.
To be more specific:With the preview pane enabled, if I select (meaning one click) a message that is not in the cache I see two logins. Using tshark on the Kolab server it looks like one login fetches the message and one login accesses the Configuration folder. That is all. I have never seen "one login per plugin" (which is what I believe you are saying that you are seeing) when selecting an email. The configuration folder is where tags are kept and if there are entries in that folder there will be some searches done within the session for tags.Subjectively (I must find out how to get some actual timings), from the time that I click on a email to the time it is displayed in the preview pane is about one second. Maybe a little more sometimes. I would love to get my message display times to be consistently < 1sec.
I am going to say user and sys on USAGE is probably the timing numbers to go against. Let's see what cyrus guys CCed on this have to say.
Cyrus guys blamed SASL but also wondered why my entropy was so low. I've done a lot of research over the past few weeks learning about entropy generation and it seems on a normal server it seems to be normal to have 1000 something.. Even on a headless server. My other production servers only have 180 and they're lightning fast. So I'm confused.
My entropy is no better than yours, but it could still be a contributing factor.
What's your entropy at? Is it headless?
I do not think that there is a single setting that is going to suddenly make Kolab perform. It is going to be the sum of a lot of things starting with the hardware and working up. Every little bit is going to help.RegardsMike
_______________________________________________
users mailing list
users@xxxxxxxxxxxxxxx
https://lists.kolab.org/mailman/listinfo/users
---- Cyrus Home Page: http://www.cyrusimap.org/ List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/ To Unsubscribe: https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
