6.0.0-git
2019-05-19

[#14021] cannot modify/delete external caldav events
Summary cannot modify/delete external caldav events
Queue Kronolith
Queue Version 4.2.8
Type Bug
State Resolved
Priority 1. Low
Owners Horde Developers (at) , jan (at) horde (dot) org
Requester martin1 (at) k0k (dot) net
Created 2015-06-20 (1429 days ago)
Due
Updated 2017-10-20 (576 days ago)
Assigned 2016-01-25 (1210 days ago)
Resolved 2017-08-25 (632 days ago)
Milestone 4.2.23
Patch No

History
2017-10-20 20:34:46 Git Commit Comment #14 Reply to this comment
Changes have been made in Git (FRAMEWORK_5_2):

commit 39d1549a4d3116f0340b99567415eb6a59167b9a
Author: Jan Schneider <jan@horde.org>
Date:   Fri, 25 Aug 2017 14:27:57 +0200

[jan] Fix updating and deleting events from external CalDAV servers 
(martin1@k0k.net, Bug #14021).

  M docs/CHANGES
  M lib/Driver/Ical.php
  M package.xml

https://github.com/horde/kronolith/commit/39d1549a4d3116f0340b99567415eb6a59167b9a
2017-08-25 12:32:35 Git Commit Comment #13 Reply to this comment
Changes have been made in Git (master):

commit 8aba6f762b6f3108366c5e290f88ad9f055b9f39
Author: Jan Schneider <jan@horde.org>
Date:   Fri Aug 25 14:25:56 2017 +0200

     [jan] Fix updating and deleting events from external CalDAV 
servers (martin1@k0k.net, Bug #14021).

  kronolith/lib/Driver/Ical.php | 2 +-
  kronolith/package.xml         | 1 +
  2 files changed, 2 insertions(+), 1 deletion(-)

http://github.com/horde/horde/commit/8aba6f762b6f3108366c5e290f88ad9f055b9f39
2017-08-25 12:29:08 Jan Schneider Comment #12
Assigned to Jan Schneider
State ⇒ Resolved
Milestone ⇒ 4.2.23		 Reply to this comment
Nice catch, thanks!
2017-08-25 12:28:14 Git Commit Comment #11 Reply to this comment
Changes have been made in Git (FRAMEWORK_5_2):

commit 04df8812cb11eec084733e5ed29b0bb602057117
Author: Jan Schneider <jan@horde.org>
Date:   Fri Aug 25 14:25:56 2017 +0200

     [jan] Fix updating and deleting events from external CalDAV 
servers (martin1@k0k.net, Bug #14021).

  kronolith/docs/CHANGES        | 2 ++
  kronolith/lib/Driver/Ical.php | 2 +-
  kronolith/package.xml         | 2 ++
  3 files changed, 5 insertions(+), 1 deletion(-)

http://github.com/horde/horde/commit/04df8812cb11eec084733e5ed29b0bb602057117
2017-08-17 09:22:43 martin1 (at) k0k (dot) net Comment #10
New Attachment: Ical.patch Download		 Reply to this comment
I believe I have have found the problem:

in file kronolith/lib/Driver/Ical.php, line 431/2 (as of kronolith 4.2.22)
_processComponents is called with one argument missing:

     431                 $this->_processComponents($results, $ical, 
null, null, false,
     432                                           false, false, $eventId);

resulting in an event with an empty $id, which in turn becomes 'ical' 
. $i in line 342.

Adding one "false, " (is that the right thing to add?) ad the 
beginning of line 433 seems to fix the problem for me (see patch 
attached).

2016-01-25 17:39:43 martin1 (at) k0k (dot) net Comment #9 Reply to this comment
If I read the logs correctly, when modifying/deleting an existing 
event, it is read once again before the actual modification, and this 
reading fails.

This log entry:

2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0003s)
         SELECT x(event_coordinates) as lat, y(event_coordinates) as lon,
           event_zoom as zoom FROM kronolith_events_mysqlgeo WHERE event_id =
           'ical0' [pid 26317 on line 321 of
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]

(copied from below)

must be a result of line 335 of 
/usr/share/php/www/horde/kronolith/lib/Driver/Ical.php, where the 
event_id of the item to be read is composed - this works when opening 
an existing event, but when modifying/deleting it, this line:

335                 $event->id = $id ? $id : 'ical' . $i;

ends in the event_id being "ical0" or "ical1" (some missing input value?).
2016-01-25 16:44:55 Jan Schneider Comment #8 Reply to this comment
Confirmed with Google Calendar.
2016-01-25 16:30:45 Jan Schneider Comment #7
Assigned to Horde DevelopersHorde Developers
State ⇒ Assigned		 Reply to this comment
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] PHP ERROR: Only 
variables should be passed by reference [pid 26317 on line 426 of 
"/usr/share/php/www/horde/kronolith/lib/Driver/Ical.php"]
This is irrelevant because it's a strict warning.
2015-10-30 14:39:16 martin1 (at) k0k (dot) net Comment #6 Reply to this comment
Bug still present as of Horde 5.2.8 / Kronolith 4.2.11

2015-08-10 16:20:13 martin1 (at) k0k (dot) net Comment #5 Reply to this comment
Bug still present as of Horde 5.2.7 / Kronolith 4.2.9
2015-06-22 19:53:24 martin1 (at) k0k (dot) net Comment #4
New Attachment: horde5.log Download		 Reply to this comment
one more line might be relevant:

2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] PHP ERROR: Only 
variables should be passed by reference [pid 26317 on line 426 of 
"/usr/share/php/www/horde/kronolith/lib/Driver/Ical.php"]

I think I'd better attach the full log, in case there is more to find 
that I didn't spot.
2015-06-22 06:10:34 martin1 (at) k0k (dot) net Comment #3 Reply to this comment
I cannot see much in the horde debug logs either (does it log the 
calls to davical at all?)

This is where the davical event is created:

2015-06-21T09:49:09+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0014s)
        SELECT object_id, object_name FROM `rampage_objects` WHERE object_name
          IN ('') AND type_id = 2 [pid 26317 on line 321 of 
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:09+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0013s)
        SELECT MAX(history_ts) FROM horde_histories WHERE history_action =
          'add' AND object_uid =
          'kronolith:http://localhost/davical/caldav.php/martin/calendar:55866c7
          5-3a94-41ab-a70b-66cd00000000' [pid 26317 on line 321 of 
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:09+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0012s)
        SELECT MAX(history_ts) FROM horde_histories WHERE history_action =
          'modify' AND object_uid =
          'kronolith:http://localhost/davical/caldav.php/martin/calendar:55866c7
          5-3a94-41ab-a70b-66cd00000000' [pid 26317 on line 321 of 
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:09+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0008s)
        SELECT x(event_coordinates) as lat, y(event_coordinates) as lon,
          event_zoom as zoom FROM kronolith_events_mysqlgeo WHERE event_id =
          '55866c75-3a94-41ab-a70b-66cd00000000.ics' [pid 26317 on line 321 
of "/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:09+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0009s)
        DELETE FROM horde_alarms WHERE alarm_id =
          '55866c75-3a94-41ab-a70b-66cd00000000' [pid 26317 on line 321 of 
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:09+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0015s)
        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-06-21 07:49:09') OR alarm_snooze <=
          '2015-06-21 07:49:09') AND (alarm_end IS NULL OR alarm_end >=
          '2015-06-21 07:49:09') AND (alarm_uid IS NULL OR alarm_uid = '' OR
          alarm_uid = 'martin') ORDER BY alarm_start, alarm_end [pid 26317 on 
line 321 of "/usr/share/php/Horde/Db/Adapter/Mysqli.php"]

And here I open it again and try to delete it:

2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0008s)
        SELECT object_id, object_name FROM `rampage_objects` WHERE object_name
          IN ('55866c75-3a94-41ab-a70b-66cd00000000') AND type_id = 2 [pid 
26317 on line 321 of "/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0003s)
        SELECT x(event_coordinates) as lat, y(event_coordinates) as lon,
          event_zoom as zoom FROM kronolith_events_mysqlgeo WHERE event_id =
          'ical0' [pid 26317 on line 321 of 
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0017s)
        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-06-21 07:49:13') OR alarm_snooze <=
          '2015-06-21 07:49:13') AND (alarm_end IS NULL OR alarm_end >=
          '2015-06-21 07:49:13') AND (alarm_uid IS NULL OR alarm_uid = '' OR
          alarm_uid = 'martin') ORDER BY alarm_start, alarm_end [pid 26317 on 
line 321 of "/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] Max memory usage: 
1835008 bytes [pid 26317 on line 609 of 
"/usr/share/php/Horde/Registry.php"]
2015-06-21T07:49:13+00:00 DEBUG: HORDE5 Load config file (conf.php; 
app: horde) [pid 26317 on line 109 of 
"/usr/share/php/Horde/Registry/Loadconfig.php"]
2015-06-21T07:49:13+00:00 DEBUG: HORDE5 [kronolith] Load config file 
(conf.php; app: kronolith) [pid 26317 on line 109 of 
"/usr/share/php/Horde/Registry/Loadconfig.php"]
2015-06-21T07:49:13+00:00 DEBUG: HORDE5 [kronolith] 
Horde_HashTable_Memory: Deleted keys 
(hht_hht_horde|nhBAMPnKLeBYAi2RBUIwfKh|martin||horde) [pid 26317 on 
line 129 of "/usr/share/php/Horde/HashTable/Base.php"]
2015-06-21T07:49:13+00:00 DEBUG: HORDE5 [kronolith] 
Horde_HashTable_Memory: Non-existent keys 
(horde|nhBAMPnKLeBYAi2RBUIwfKh|martin||horde) [pid 26317 on line 240 
of "/usr/share/php/Horde/HashTable/Base.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] 
Horde_HashTable_Memory: Deleted keys 
(hht_hht_kronolith.tagger.type_ids) [pid 26317 on line 129 of 
"/usr/share/php/Horde/HashTable/Base.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] 
Horde_HashTable_Memory: Deleted keys 
(hht_hht_kronolith.tagger.type_ids_t) [pid 26317 on line 129 of 
"/usr/share/php/Horde/HashTable/Base.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] 
Horde_HashTable_Memory: Non-existent keys 
(kronolith.tagger.type_ids,kronolith.tagger.type_ids_t) [pid 26317 on 
line 240 of "/usr/share/php/Horde/HashTable/Base.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0003s)
        SELECT user_id, user_name FROM `rampage_users` WHERE user_name IN
          ('martin') [pid 26317 on line 321 of 
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0003s)
        SELECT t.tag_id AS tag_id, tag_name, count FROM `rampage_tagged`
          tagged INNER JOIN `rampage_tags` t ON tagged.tag_id = t.tag_id INNER
          JOIN `rampage_user_tag_stats` uts ON t.tag_id = uts.tag_id AND
          uts.user_id = 2 GROUP BY t.tag_id, tag_name, count ORDER BY count DESC
          LIMIT 10 [pid 26317 on line 321 of 
"/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0004s)
        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-06-21 07:49:13') OR alarm_snooze <=
          '2015-06-21 07:49:13') AND (alarm_end IS NULL OR alarm_end >=
          '2015-06-21 07:49:13') AND (alarm_uid IS NULL OR alarm_uid = '' OR
          alarm_uid = 'martin') ORDER BY alarm_start, alarm_end [pid 26317 on 
line 321 of "/usr/share/php/Horde/Db/Adapter/Mysqli.php"]
2015-06-21T09:49:13+02:00 DEBUG: HORDE5 [kronolith] Max memory usage: 
1572864 bytes [pid 26317 on line 609 of 
"/usr/share/php/Horde/Registry.php"]
2015-06-21T07:49:17+00:00 DEBUG: HORDE5 Load config file (conf.php; 
app: horde) [pid 26317 on line 109 of 
"/usr/share/php/Horde/Registry/Loadconfig.php"]
2015-06-21T07:49:17+00:00 DEBUG: HORDE5 [kronolith] Load config file 
(conf.php; app: kronolith) [pid 26317 on line 109 of 
"/usr/share/php/Horde/Registry/Loadconfig.php"]
2015-06-21T07:49:17+00:00 DEBUG: HORDE5 [kronolith] 
Horde_HashTable_Memory: Deleted keys 
(hht_hht_horde|nhBAMPnKLeBYAi2RBUIwfKh|martin||horde) [pid 26317 on 
line 129 of "/usr/share/php/Horde/HashTable/Base.php"]
2015-06-21T07:49:17+00:00 DEBUG: HORDE5 [kronolith] 
Horde_HashTable_Memory: Non-existent keys 
(horde|nhBAMPnKLeBYAi2RBUIwfKh|martin||horde) [pid 26317 on line 240 
of "/usr/share/php/Horde/HashTable/Base.php"]
2015-06-21T09:49:17+02:00 DEBUG: HORDE5 [kronolith] SQL  (0,0017s)
        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-06-21 07:49:17') OR alarm_snooze <=
          '2015-06-21 07:49:17') AND (alarm_end IS NULL OR alarm_end >=
          '2015-06-21 07:49:17') AND (alarm_uid IS NULL OR alarm_uid = '' OR
          alarm_uid = 'martin') ORDER BY alarm_start, alarm_end [pid 26317 on 
line 321 of "/usr/share/php/Horde/Db/Adapter/Mysqli.php"]

Davical sees:

[Sun Jun 21 09:49:09.127830 2015] [:error] [pid 26313] [client 
127.0.0.1:45166] davical: LOG: :PUT 
/davical/caldav.php/martin/calendar/55866c75-3a94-41ab-a70b-66cd00000000.ics

(...)

[Sun Jun 21 09:49:13.613334 2015] [:error] [pid 26527] [client 
127.0.0.1:45169] davical: LOG: :GET 
/davical/caldav.php/martin/calendar/55866c75-3a94-41ab-a70b-66cd00000000.ics

(...)

[Sun Jun 21 09:49:17.623577 2015] [:error] [pid 26554] [client 
127.0.0.1:45172] davical: LOG: :GET 
/davical/caldav.php/martin/calendar/ical0

2015-06-20 15:35:56 Michael Rubinsky Comment #2
State ⇒ Feedback
Priority ⇒ 1. Low		 Reply to this comment
Enable debug logging in the Horde log and review/post any relevant entries.
2015-06-20 09:37:41 martin1 (at) k0k (dot) net Comment #1
Type ⇒ Bug
Queue ⇒ Kronolith
State ⇒ Unconfirmed
Priority ⇒ 2. Medium
Summary ⇒ cannot modify/delete external caldav events
Patch ⇒ No
Milestone ⇒ 		Reply to this comment
I have an external caldav calendar in Kronolith (Davical 1.1.3.1). I 
can view and add events, but I cannot modify or delete events. Access 
from Lightning works fine, using Lightning I can also modify/delete 
events created by Kronolith.

When I try to modify/delete an event with Kronolith I get a "Resource 
not found" error and the following Apache log:

127.0.0.1 - martin [20/Jun/2015:10:51:21 +0200] "GET 
/davical/caldav.php/martin/calendar/ical0 HTTP/1.1" 404 465 "-" 
"Horde_Http 2.1.5"

sometimes I see ical1 instead of ical0.

Creating this very event looked like this:

127.0.0.1 - martin [20/Jun/2015:10:51:11 +0200] "PUT 
/davical/caldav.php/martin/
calendar/5585297f-1ed8-483c-9d06-5c4e00000000.ics HTTP/1.1" 201 485 
"-" "Horde_H
ttp 2.1.5"

This is not a recent regression, it has been like this for quite some 
time (I have logs back to October 2014, but it might be older).

My guess is that Kronolith somehow doesn't get the event ID right (but 
my understanding of Horde code ends here...).

I have tried deleting/re-adding the external calendar in Kronolith and 
creating a new principal in Davical but the problem remained the same. 
Davical logs show nothing interesting, other than the fact that Horde 
requested "ical0" which does not exist.

I have seen that Apache mod_rewrite can create problems, so I have 
tried disabling mod_rewrite, but it didn't change anything. Anyway, I 
have no rewrite rules enabled.

Thanks in advance for any hint! If I can help with any log- or 
conf-files, please let me know.

Martin
New Ticket
My Tickets
Search
Query Builder
Reports

Saved Queries

Open Bugs
Bugs waiting for Feedback
Open Bugs in Releases
Open Enhancements
Enhancements waiting for Feedback
Bugs with Patches
Enhancements with Patches
Release Showstoppers
Stalled Tickets
New Tickets
Horde 5 Showstoppers