Hi Guys
Still having an issue with slow imap queries via overlook (its a
squirrelmail base with changes in gui, we've also tested squirrelmail with
same results),
We're getting *very* slow queries on some mailboxes below ive provided a
level 5 trace log
This client has 14mb of mail which is about 280 emails or so
Can anyone shed some light on this?
The database is running on a dedicated server with very little load on it
and im testing this from a spare failover webserver with the same results as
the live webserver so im confident its not an I/O error machines are also on
a bonded gigabit connection to eachother.
I saw a bug filed for a similar issue, is this still outstanding? Bug id
579, i wonder if its related?
Not sure if you can see anything obvious from those tracelogs, if anyone has
any ideas on how to fix this please let me know!
Regards
Jon
Jun 27 20:22:52 webmail-1 dbmail/imap4d[4840]: Debug:[misc]
misc.c,g_tree_merge(+1267): (0x808aad8) (0x8087768): a[0] [OR] b[266] ->
a[266]
Jun 27 20:22:52 webmail-1 dbmail/imap4d[4840]: Debug:[mailbox]
dbmail-mailbox.c,_do_search(+1569): [0x809ff00] depth [1] type [2] rows
[266]
Jun 27 20:22:52 webmail-1 dbmail/imap4d[4840]: Debug:[mailbox]
dbmail-mailbox.c,dbmail_mailbox_get_set(+1387): [1:*] uid [1]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[serverchild]
serverchild.c,select_and_accept(+252): received connection
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[serverchild]
serverchild.c,select_and_accept(+275): connection accepted
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Message:[serverchild]
serverchild.c,PerformChildTask(+341): incoming connection from [127.0.0.1]
by pid [4839]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[serverchild]
serverchild.c,PerformChildTask(+366): client info init complete, calling
client handler
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [* OK
dbmail imap (protocol version 4r1) server 2.2 ready to run^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+175): COMMAND: [A0001 LOGIN
"addiscombe.addiscombe.org" "monty1"]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[0]:
'addiscombe.addiscombe.org'
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[1]: 'monty1'
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+288): Executing command login...
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_handle_auth(+1554): trying to
validate user [addiscombe.addiscombe.org], pass [XXXX]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT userid FROM dbmail_usermap WHERE 1 =
2]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_use_usermap(+167): enabling usermap lookups
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_usermap_resolve(+4536): checking userid [addiscombe.addiscombe.org]
in usermap
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_usermap_resolve(+4547): client on inet socket [inet:127.0.0.1:143]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT login, sock_allow, sock_deny, userid
FROM dbmail_usermap WHERE login in ('addiscombe.addiscombe.org','ANY') ORDER
BY sock_allow, sock_deny]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_usermap_resolve(+4573): login [addiscombe.addiscombe.org] not found
in usermap
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT user_idnr FROM dbmail_users WHERE
lower(userid) = lower('addiscombe.addiscombe.org')]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT user_idnr, passwd, encryption_type
FROM dbmail_users WHERE user_idnr = 2581]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[auth]
authsql.c,auth_validate(+401): validating using plaintext passwords
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [UPDATE dbmail_users SET last_login =
'2007-06-27 20:23:08' WHERE user_idnr = 2581]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Message:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_handle_auth(+1559): user (id:2581,
name addiscombe.addiscombe.org) tries login
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Message:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_handle_auth(+1580): user (id 2581,
name addiscombe.addiscombe.org) login accepted
Jun 27 20:23:08 webmail-1 in.imapproxyd[3403]: LOGIN:
'"addiscombe.addiscombe.org"' (127.0.0.1:57553) on new sd [11]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [A0001 OK
LOGIN completed^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+307): Finished command login [0]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+175): COMMAND: [A002 CAPABILITY]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+288): Executing command capability...
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1452): RESPONSE: [*
CAPABILITY IMAP4 IMAP4rev1 AUTH=LOGIN ACL NAMESPACE CHILDREN SORT QUOTA
THREAD=ORDEREDSUBJECT UNS...]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [A002 OK
CAPABILITY completed^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+307): Finished command capability [0]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+175): COMMAND: [A003 NAMESPACE]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+288): Executing command namespace...
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [*
NAMESPACE (("" "/")) (("#Users" "/")) (("#Public" "/"))^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [A003 OK
NAMESPACE complete^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+307): Finished command namespace [0]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+175): COMMAND: [C64 UNSELECT]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+288): Executing command unselect...
Jun 27 20:23:08 webmail-1 in.imapproxyd[3403]: LOGOUT:
'"addiscombe.addiscombe.org"' from server sd [11]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [C64 BAD
UNSELECT command received in invalid state^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+307): Finished command unselect [1]
Jun 27 20:23:08 webmail-1 in.imapproxyd[3403]: LOGIN:
'"addiscombe.addiscombe.org"' (127.0.0.1:57555) on existing sd [11]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+175): COMMAND: [A002 STATUS "INBOX" (MESSAGES
UNSEEN RECENT)]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[0]: 'INBOX'
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[1]: '('
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[2]: 'MESSAGES'
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[3]: 'UNSEEN'
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[4]: 'RECENT'
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[5]: ')'
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+288): Executing command status...
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_findmailbox(+2519): looking for mailbox with FQN [INBOX].
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT mailbox_idnr FROM dbmail_mailboxes
WHERE name LIKE 'INBOX' AND owner_idnr=2581]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_acl_has_right(+4064): checking ACL [read_flag] for user [2581] on
mailbox [4945]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT owner_idnr FROM dbmail_mailboxes
WHERE mailbox_idnr = 4945]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_acl_has_right(+4075): mailbox [4945] is owned by user [2581], giving
all rights
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT
permission,seen_flag,answered_flag,deleted_flag,flagged_flag,recent_flag,dra
ft_flag FROM dbmail_mailboxes WHERE mailbox_idnr = 4945]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT 'a',COUNT(*) FROM dbmail_messages
WHERE mailbox_idnr=4945 AND (status < 2) UNION SELECT 'b',COUNT(*) FROM
dbmail_messages WHERE mailbox_idnr=4945 AND (status < 2) AND seen_flag=1
UNION SELECT 'c',COUNT(*) FROM dbmail_messages WHERE mailbox_idnr=4945 AND
(status < 2) AND recent_flag=1]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT message_idnr+1 FROM dbmail_messages
WHERE mailbox_idnr=4945 ORDER BY message_idnr DESC LIMIT 1]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [* STATUS
"INBOX" (MESSAGES 266 UNSEEN 170 RECENT 0)^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [A002 OK
STATUS completed^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+307): Finished command status [0]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+175): COMMAND: [A003 SELECT "INBOX"]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,build_args_array_ext(+2398): arg[0]: 'INBOX'
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Info:[imap]
imap4.c,IMAPClientHandler(+288): Executing command select...
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_findmailbox(+2519): looking for mailbox with FQN [INBOX].
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT mailbox_idnr FROM dbmail_mailboxes
WHERE name LIKE 'INBOX' AND owner_idnr=2581]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_acl_has_right(+4064): checking ACL [read_flag] for user [2581] on
mailbox [4945]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT owner_idnr FROM dbmail_mailboxes
WHERE mailbox_idnr = 4945]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[db]
db.c,db_acl_has_right(+4075): mailbox [4945] is owned by user [2581], giving
all rights
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT no_select FROM dbmail_mailboxes
WHERE mailbox_idnr = 4945]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT
permission,seen_flag,answered_flag,deleted_flag,flagged_flag,recent_flag,dra
ft_flag FROM dbmail_mailboxes WHERE mailbox_idnr = 4945]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT 'a',COUNT(*) FROM dbmail_messages
WHERE mailbox_idnr=4945 AND (status < 2) UNION SELECT 'b',COUNT(*) FROM
dbmail_messages WHERE mailbox_idnr=4945 AND (status < 2) AND seen_flag=1
UNION SELECT 'c',COUNT(*) FROM dbmail_messages WHERE mailbox_idnr=4945 AND
(status < 2) AND recent_flag=1]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT message_idnr+1 FROM dbmail_messages
WHERE mailbox_idnr=4945 ORDER BY message_idnr DESC LIMIT 1]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT message_idnr FROM dbmail_messages
WHERE mailbox_idnr = 4945 AND status IN (0,1) ORDER BY message_idnr]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[mailbox]
dbmail-mailbox.c,mailbox_build_uid_map(+180): ids [266], msn [266]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[sql]
dbmysql.c,db_query(+290): query [SELECT seen_flag, answered_flag,
deleted_flag, flagged_flag, draft_flag, recent_flag,
DATE_FORMAT(internal_date, '%Y-%m-%d %T'), rfcsize, message_idnr FROM
dbmail_messages msg, dbmail_physmessage pm WHERE pm.id = msg.physmessage_id
AND message_idnr BETWEEN 21724194 AND 66992769 AND mailbox_idnr = 4945 AND
status IN (0,1) ORDER BY message_idnr ASC]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [* 266
EXISTS^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [* 0
RECENT^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [* FLAGS
(\Seen \Answered \Deleted \Flagged \Draft)^M ]
Jun 27 20:23:08 webmail-1 dbmail/imap4d[4839]: Debug:[imapsession]
dbmail-imapsession.c,dbmail_imap_session_printf(+1450): RESPONSE: [* OK
[PERMANENTFLAGS (\Seen \Answered \Deleted \Flagged \Draft)]^M ]
Regards
Jon Duggan
Nuco Technologies Ltd
[EMAIL PROTECTED]
Tel. 0870 165 1300
_______________________________________________
DBmail mailing list
[email protected]
https://mailman.fastxs.nl/mailman/listinfo/dbmail
