[horde] DEBUG doesn't show slow query - max exec time exceeded
rick at havokmon.com
rick at havokmon.com
Wed Sep 10 15:54:27 UTC 2014
I can't login to Horde5 with ONE account (my own of course). All other
accounts work, no one else seems to have an issue.
Basically, I leave my session open all night, and when I came in this
morning my last email shown was around 3am, and the web interface would
say 'Server not responding'. After logging out, and back in, I now
ALWAYS get:
ErrorException Object
(
[message:protected] => Maximum execution time of 30 seconds exceeded
[string:Exception:private] =>
[code:protected] => 0
[file:protected] => /usr/share/php/Horde/Db/Adapter/Base.php
[line:protected] => 747
[trace:Exception:private] => Array
(
[0] => Array
(
[function] => catchFatalError
[class] => Horde_ErrorHandler
[type] => ::
[args] => Array
(
)
)
)
[previous:Exception:private] =>
[severity:protected] => 1
[logged] => 1
Enabling DEBUG, I managed to pull the following out:
2014-09-10T10:22:48-05:00 DEBUG: HORDE5 [horde] Horde_Prefs: Storing
preference value (last_login) [pid 3282 on line 82 of
"/usr/share/horde/lib/LoginTasks/Task/LastLogin.php"]
2014-09-10T10:22:48-05:00 DEBUG: HORDE5 [horde] Horde_Prefs: Storing
preference value (last_logintasks) [pid 3282 on line 98 of
"/usr/share/php/Horde/Core/LoginTasks/Backend/Horde.php"]
2014-09-10T10:22:48-05:00 DEBUG: HORDE5 [gollem] Load config file
(conf.php; app: gollem) [pid 3282 on line 109 of
"/usr/share/php/Horde/Registry/Loadconfig.php"]
2014-09-10T10:22:49-05:00 DEBUG: HORDE5 [imp] SQL (0.0003s)
SELECT t.field, t.data FROM horde_imap_client_data d INNER JOIN
horde_imap_client_metadata t ON d.messageid = t.messageid
WHERE
d.hostspec = 'localhost' AND d.port = '1143' AND d.username =
'rick at havokmon.com' AND d.mailbox = 'INBOX' AND (t.field =
'_m' OR
t.field = 'uidvalid') [pid 3282 on line 320 of
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2014-09-10T10:22:49-05:00 DEBUG: HORDE5 [imp] Horde_HashTable_Memcache:
Retrieved keys
(horde5Horde_Db_Adapter_Mysqli0571bbe8tables/columns/horde_imap_client_metadata)
[pid 3282 on line 233 of "/usr/share/php/Horde/HashTable/Base.php"]
2014-09-10T10:22:49-05:00 DEBUG: HORDE5 [imp] SQL (0.0002s)
SELECT t.field, t.data FROM horde_imap_client_data d INNER JOIN
horde_imap_client_metadata t ON d.messageid = t.messageid
WHERE
d.hostspec = 'localhost' AND d.port = '1143' AND d.username =
'rick at havokmon.com' AND d.mailbox = 'INBOX' AND (t.field =
'uidvalid') [pid 3282 on line 320 of
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2014-09-10T10:22:49-05:00 DEBUG: HORDE5 [imp] Horde_HashTable_Memcache:
Retrieved keys
(horde5Horde_Db_Adapter_Mysqli0571bbe8tables/columns/horde_imap_client_metadata)
[pid 3282 on line 233 of "/usr/share/php/Horde/HashTable/Base.php"]
2014-09-10T10:22:49-05:00 DEBUG: HORDE5 [imp] SQL (0.0007s)
SELECT DISTINCT t.msguid FROM horde_imap_client_data d INNER
JOIN
horde_imap_client_message t ON d.messageid = t.messageid WHERE
d.hostspec = 'localhost' AND d.port = '1143' AND d.username =
'rick at havokmon.com' AND d.mailbox = 'INBOX' [pid 3282 on line
320 of "/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
-- SNIP -- There's other users using ActiveSync.. these appear to all be
related to me
2014-09-10T10:23:18-05:00 EMERG: HORDE5 [imp] Maximum execution time of
30 seconds exceeded [pid 3282 on line 747 of
"/usr/share/php/Horde/Db/Adapter/Base.php"]
2014-09-10T10:23:18-05:00 DEBUG: HORDE5 1.
Horde_ErrorHandler::catchFatalError()
2014-09-10T10:23:18-05:00 DEBUG: HORDE5 [imp] SQL (0.0003s)
(Some other Query)
It appears, under normal circumstance, that the 'Some Other Query' is
replaced with the actual QUERY in debug mode. But in this case, it's
not shown. While this query is 'waiting', my MySQL server is not
processing any requests, so I'm really unsure what's really going on.
I've deleted all my prefs (as that sometimes has hosed things in the
past, to no avail).
I've also logged in as a different admin user and manually deleted my
sessions from the horde_sessionHandler table, just to be sure.
Also, I've cleaned up my INBOX incase it was related to INBOX size. I
see the next table is probably horde_imap_client_message - how would I
clean that up for just my user? Or can those safely be emptied?
MAYBE RELATED?
I do also see these, but I can't find an 8Mb limit anywhere - and it
doesn't seem to be for my user.
2014-09-10T10:22:57-05:00 DEBUG: HORDE5 [imp] SQL (0.0008s)
SELECT alarm_id, alarm_uid, alarm_start, alarm_end,
alarm_methods,
<etc> FOR A DIFFERENT USER.
2014-09-10T10:22:57-05:00 DEBUG: HORDE5 [imp] Max memory usage: 7077888
bytes
I run Horde5 on Debian via lighttpd and php-cgi - 128Mb max memory usage
(I upped to 180 for testing, no change for either error)
Any suggestions would be greatly appreciated.
More information about the horde
mailing list