Summary | ActiveSync SQL error |
Queue | Synchronization |
Queue Version | FRAMEWORK_5_2 |
Type | Bug |
State | Not Reproducible |
Priority | 2. Medium |
Owners | mrubinsk (at) horde (dot) org |
Requester | o+horde (at) immerda (dot) ch |
Created | 12/03/2015 (3501 days ago) |
Due | |
Updated | 12/25/2015 (3479 days ago) |
Assigned | 12/03/2015 (3501 days ago) |
Resolved | 12/25/2015 (3479 days ago) |
Github Issue Link | |
Github Pull Request | |
Milestone | |
Patch | No |
State ⇒ Not Reproducible
being captured in Horde_Share_Sql::_listAllShares(). Look at the code
around line 324:
if (!empty($data['share_name'])) {
$sharelist[$data['share_name']] = $this->_createObject($data);
} else {
$sharelist[] = $this->_createObject($data);
}
and start digging there.
even integers. Look in your share table (probably
kronolith_sharesng) and see if you can find any shares with a share
name of 0 or 1 (or ANY integer value). My guess is those are old
left over cruft.
there. I tried:
SELECT * FROM "public"."kronolith_sharesng" WHERE
char_length("share_name") < 10
and
CREATE OR REPLACE FUNCTION convert_to_integer(v_input text)
RETURNS INTEGER AS $$
DECLARE v_int_value INTEGER DEFAULT NULL; BEGIN
BEGIN
v_int_value := v_input::INTEGER;
EXCEPTION WHEN OTHERS THEN
RETURN NULL;
END;
RETURN v_int_value;
END;
$$ LANGUAGE plpgsql;
SELECT * FROM "public"."kronolith_sharesng" where
convert_to_integer("share_name") is not null
none of those queries returned a single row
integers. Look in your share table (probably kronolith_sharesng) and
see if you can find any shares with a share name of 0 or 1 (or ANY
integer value). My guess is those are old left over cruft.
[1451]=>
int(0)
[1452]=>
int(1)
What should we do about them?
is the query for the last share in "SELECT * FROM kronolith_sharesng
ORDER BY share_name ASC" (which according to the debug log seems to
be query used by horde-alarms to get the list of shares).
shares from kronolith_sharesng have already been processed.
produces (using Kronolith's scope):
$kronolith_shares = $injector->getInstance('Kronolith_Shares');
var_dump(array_keys($kronolith_shares->listAllShares()));
See if there are any "empty-ish" values listed.
kronolith issue. At least I see the same issue arise on our hosts
which do not get any ActiveSync traffic at all.
issues. The SQL error is caused solely by horde-alarms and the
activeSync error is a different one. They just looked related since
the activeSync ping interval and the horde-alarms cronjob have a
similar frequency.
is the query for the last share in "SELECT * FROM kronolith_sharesng
ORDER BY share_name ASC" (which according to the debug log seems to
be query used by horde-alarms to get the list of shares).
shares from kronolith_sharesng have already been processed.
listed first in the trace.
kronolith issue. At least I see the same issue arise on our hosts
which do not get any ActiveSync traffic at all.
I found out that every run of the horde-alarms cron job triggers the
error too. Unfortunately even full debug level does not yield a better
error.
Additionally I found out that the last entry before the error occurs
is the query for the last share in "SELECT * FROM kronolith_sharesng
ORDER BY share_name ASC" (which according to the debug log seems to be
query used by horde-alarms to get the list of shares).
On the other hand the number of 'select .... from kronolith_events
...' queries does not match the number of entries in
kronolith_sharesng, but maybe that's ok, since there seem to be
duplicate names with different flags (from the migration from old
style per-user calendar entries, it seems).
Any other things I could try?
For reference the error with full debug on looks like this:
2015-12-03T15:33:31+01:00 DEBUG: HORDE [kronolith] SQL
SELECT event_id, event_uid, event_description, event_location,
event_private, event_status, event_attendees, event_title,
event_recurcount, event_url, event_timezone, event_recurtype,
event_recurenddate, event_recurinterval, event_recurdays,
event_start,
event_end, event_allday, event_alarm, event_alarm_methods,
event_modified, event_exceptions, event_creator_id, event_resources,
event_baseid, event_exceptionoriginaldate FROM
kronolith_events WHERE
calendar_id = 0 AND event_alarm > 0 AND ((event_end >= '2015-12-02
23:00:00') OR (event_recurenddate >= '2015-12-02 23:00:00' AND
event_recurtype <> 0)) [pid 31771 on line 233 of
"pear/php/Horde/Db/Adapter/Pdo/Base.php"]
2015-12-03T15:33:31+01:00 ERR: HORDE [kronolith] SQL QUERY FAILED:
SQLSTATE[42883]: Undefined function: 7 ERROR: operator does not
exist: character varying = integer
LINE 1: ...ginaldate FROM kronolith_events WHERE calendar_id = 0 AND ev...
^
HINT: No operator matches the given name and argument type(s). You
might need to add explicit type casts.
SELECT event_id, event_uid, event_description, event_location,
event_private, event_status, event_attendees, event_title,
event_recurcount, event_url, event_timezone, event_recurtype,
event_recurenddate, event_recurinterval, event_recurdays,
event_start,
event_end, event_allday, event_alarm, event_alarm_methods,
event_modified, event_exceptions, event_creator_id, event_resources,
event_baseid, event_exceptionoriginaldate FROM
kronolith_events WHERE
calendar_id = 0 AND event_alarm > 0 AND ((event_end >= '2015-12-02
23:00:00') OR (event_recurenddate >= '2015-12-02 23:00:00' AND
event_recurtype <> 0)) [pid 31771 on line 234 of
"pear/php/Horde/Db/Adapter/Pdo/Base.php"]
2015-12-03T15:33:31+01:00 DEBUG: HORDE [horde] SQL (0.0095s)
SELECT alarm_id, alarm_uid, alarm_start, alarm_end, alarm_methods,
alarm_params, alarm_title, alarm_text, alarm_snooze, alarm_internal
FROM horde_alarms WHERE alarm_dismissed = 0 AND
((alarm_snooze IS NULL
AND alarm_start <= '2015-12-03 14:33:19') OR alarm_snooze <=
'2015-12-03 14:33:19') AND (alarm_end IS NULL OR alarm_end >=
'2015-12-03 14:33:19') ORDER BY alarm_start, alarm_end [pid
31771 on line 238 of "pear/php/Horde/Db/Adapter/Pdo/Base.php"]
2015-12-03T15:33:31+01:00 DEBUG: HORDE [horde] Max memory usage:
37486592 bytes [pid 31771 on line 609 of "pear/php/Horde/Registry.php"]
Assigned to Michael Rubinsky
State ⇒ Feedback
listed first in the trace.
To further debug this issue, we need details of the Horde -> Device
connection. It may also be beneficial to obtain a network capture.
To enable debugging, see instructions contained in the ActiveSync
section of Horde's configuration. Also, see
http://wiki.horde.org/ActiveSync for more details.
Debugging should not be enabled on a production server, Attach/post
only the portion of the log that directly deals with the problem
reported (it may be simplest to clear the log file and then perform
the event that causes the error).
Patch ⇒ No
State ⇒ Unconfirmed
Milestone ⇒
Queue ⇒ Synchronization
Summary ⇒ ActiveSync SQL error
Type ⇒ Bug
Priority ⇒ 2. Medium
2015-12-03T08:33:33+00:00 ERR: HORDE Returning HTTP 500 while handling
Sync command. Error is: Protocol error [pid 20755 on line 160 of
"www/rpc.php"]
2015-12-03T08:33:33+00:00 ERR: HORDE Error in communicating with
ActiveSync server: Protocol error [pid 20755 on line 165 of
"pear/php/Horde/Rpc/ActiveSync.php"]
2015-12-03T08:33:33+00:00 ERR: HORDE #0
pear/php/Horde/ActiveSync/Request/Sync.php(201):
Horde_ActiveSync_Request_Sync->_parseSyncFolders()
#1pear/php/Horde/ActiveSync/Request/Base.php(253):Horde_ActiveSync_Request_Sync->_handle()
#2pear/php/Horde/ActiveSync.php(803): Horde_ActiveSync_Request_Base->handle()#3pear/php/Horde/Rpc/ActiveSync.php(143):Horde_ActiveSync->handleRequest('Sync', 'SEC17314EC9E896...')
#4www/rpc.php(160): Horde_Rpc_ActiveSync->getResponse(NULL)#5{main} [pid 20755 on line 165 of "pear/php/Horde/Rpc/ActiveSync.php"]2015-12-03T08:33:33+00:00 ERR: HORDE Buffer contents: [pid 20755 on
line 165 of "pear/php/Horde/Rpc/ActiveSync.php"]
2015-12-03T09:35:15+01:00 ERR: HORDE [kronolith] SQL QUERY FAILED:
SQLSTATE[42883]: Undefined function: 7 ERROR: operator does not
exist: character varying = integer
LINE 1: ...ginaldate FROM kronolith_events WHERE calendar_id = 0 AND ev...
^
HINT: No operator matches the given name and argument type(s). You
might need to add explicit type casts.
SELECT event_id, event_uid, event_description, event_location,
event_private, event_status, event_attendees, event_title,
event_recurcount, event_url, event_timezone, event_recurtype,
event_recurenddate, event_recurinterval, event_recurdays,
event_start,
event_end, event_allday, event_alarm, event_alarm_methods,
event_modified, event_exceptions, event_creator_id, event_resources,
event_baseid, event_exceptionoriginaldate FROM
kronolith_events WHERE
calendar_id = 0 AND event_alarm > 0 AND ((event_end >= '2015-12-02
23:00:00') OR (event_recurenddate >= '2015-12-02 23:00:00' AND
event_recurtype <> 0)) [pid 24338 on line 234 of
"pear/php/Horde/Db/Adapter/Pdo/Base.php"]
Not exactly sure how the problem presents to users. The affected
clients seem to cause quite more sync traffic though.