6.0.0-git
▾
Tasks
New Task
Search
Photos
Wiki
▾
Tickets
New Ticket
Search
Toggle Alerts Log
Help
2020-07-15
History
Attachments
Comment
Watch
Download
Comment on [#13034] CalDav Sync with Kolab Backend
*
Your Email Address
*
Spam protection
Enter the letters below:
. ..__ . .\ /. . |_/ [__)| | >< | | | \| |/\|/ \|__|
Comment
> Here is the only backtraces I see (after eliminating some others > which were all red herings). This backtrace comes at the very > beginning of a CalDaV session and only once: > > ``` > 2019-05-12T00:48:57+02:00 EMERG: HORDE Invalid VObject, line 1 did > not follow the icalendar/vcard format [pid 17266 on line 143 of > "/usr/share/php/Sabre/VObject/Reader.php"] > 2019-05-12T00:48:57+02:00 DEBUG: HORDE 1. > Horde_Rpc_Webdav->getResponse() /usr/share/horde/rpc.php:160 > 2. Sabre\DAV\Server->exec() /usr/share/php/Horde/Rpc/Webdav.php:66 > 3. Sabre\DAV\Server->invokeMethod() /usr/share/php/Sabre/DAV/Server.php:214 > 4. call_user_func() /usr/share/php/Sabre/DAV/Server.php:474 > 5. Sabre\DAV\Server->httpReport() > 6. Sabre\DAV\Server->broadcastEvent() > /usr/share/php/Sabre/DAV/Server.php:1066 > 7. call_user_func_array() /usr/share/php/Sabre/DAV/Server.php:433 > 8. Sabre\CalDAV\Plugin->report() > 9. Sabre\CalDAV\Plugin->calendarQueryReport() > /usr/share/php/Sabre/CalDAV/Plugin.php:265 > 10. Sabre\CalDAV\Calendar->calendarQuery() > /usr/share/php/Sabre/CalDAV/Plugin.php:591 > 11. Sabre\CalDAV\Backend\AbstractBackend->calendarQuery() > /usr/share/php/Sabre/CalDAV/Calendar.php:372 > 12. Sabre\CalDAV\Backend\AbstractBackend->validateFilterForObject() > /usr/share/php/Sabre/CalDAV/Backend/AbstractBackend.php:119 > 13. Sabre\VObject\Reader::read() > /usr/share/php/Sabre/CalDAV/Backend/AbstractBackend.php:147 > 14. Sabre\VObject\Reader::readLine() > /usr/share/php/Sabre/VObject/Reader.php:70 > > 2019-05-12T00:48:57+02:00 DEBUG: HORDE [horde] Max memory usage: > 58720256 bytes [pid 18996 on line 613 of > "/usr/share/php/Horde/Registry.php"] > 2019-05-12T00:48:59+02:00 EMERG: HORDE Allowed memory size of > 536870912 bytes exhausted (tried to allocate 467668992 bytes) [pid > 17266 on line 130 of "/usr/share/php/Horde/ErrorHandler.php"] > 2019-05-12T00:48:59+02:00 DEBUG: HORDE 1. > Horde_ErrorHandler::catchFatalError() > > 2019-05-12T00:48:59+02:00 WARN: HORDE PHP ERROR: Cannot modify header > information - headers already sent [pid 17266 on line 0 of "Unknown"] > 2019-05-12T00:48:59+02:00 DEBUG: HORDE 1. Horde_ErrorHandler::errorHandler() > ``` > > Then I see similar log passages for each event that's being exchanged > between client and server. Some look like this: > > ``` > 2019-05-11T23:41:00+00:00 DEBUG: HORDE Load config file (conf.php; > app: horde) [pid 25876 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:41:00+00:00 DEBUG: HORDE Load config file (nls.php; > app: horde) [pid 25876 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:41:00+00:00 DEBUG: HORDE [horde] Horde_Rpc::__construct > complete [pid 25876 on line 45 of > "/usr/share/php/Horde/Rpc/Webdav.php"] > 2019-05-11T23:41:00+00:00 DEBUG: HORDE Horde_Rpc::authorize() > starting [pid 25876 on line 137 of "/usr/share/horde/rpc.php"] > 2019-05-11T23:41:00+00:00 DEBUG: HORDE Load config file (prefs.php; > app: horde) [pid 25876 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:41:00+00:00 DEBUG: HORDE Load config file (conf.php; > app: horde) [pid 25876 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:41:00+00:00 DEBUG: HORDE Load config file (conf.php; > app: ) [pid 25876 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:41:01+00:00 DEBUG: HORDE [kronolith] Load config file > (conf.php; app: kronolith) [pid 25876 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:41:01+00:00 DEBUG: HORDE [kronolith] Load config file > (prefs.php; app: kronolith) [pid 25876 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieving namespaces. [pid 25876 > on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieved namespaces > [Horde_Kolab_Storage_Folder_Namespace_Imap: "INBOX" (personal, "/"), > "user" (other, "/"), "" (shared, "/")]. [pid 25876 on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] REQUEST OUT IMAP: > 0 ms [getNamespace] [pid 25876 on line 276 of > "/usr/share/php/Horde/Kolab/Storage/List/Tools.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieving namespaces. [pid 25876 > on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieved namespaces > [Horde_Kolab_Storage_Folder_Namespace_Imap: "INBOX" (personal, "/"), > "user" (other, "/"), "" (shared, "/")]. [pid 25876 on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] REQUEST OUT IMAP: > 0 ms [getNamespace] [pid 25876 on line 276 of > "/usr/share/php/Horde/Kolab/Storage/List/Tools.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieving namespaces. [pid 25876 > on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieved namespaces > [Horde_Kolab_Storage_Folder_Namespace_Imap: "INBOX" (personal, "/"), > "user" (other, "/"), "" (shared, "/")]. [pid 25876 on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] REQUEST OUT IMAP: > 0 ms [getNamespace] [pid 25876 on line 276 of > "/usr/share/php/Horde/Kolab/Storage/List/Tools.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Load config file > (prefs.php; app: horde) [pid 25876 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Fetching stamp WITH token. [pid 25876 on line 252 of > "/usr/share/php/Horde/Kolab/Storage/Data/Cached.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Synchronized data > cache for INBOX/Kalender. [pid 25876 on line 63 of > "/usr/share/php/Horde/Kolab/Storage/Synchronization/OncePerSession.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] INBOX/Kalender has > 30 objects [too many to list]. [pid 25876 on line 114 of > "/usr/share/horde/kronolith/lib/Driver/Kolab.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Fetching stamp WITH token. [pid 25876 on line 252 of > "/usr/share/php/Horde/Kolab/Storage/Data/Cached.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Incremental folder sync: user: m.gabriel@das-netzwerkteam.de, folder: > INBOX/Kalender, last_sync: 1557618061, current_sync: 1557618061, > changes: Array > ( > [add] => Array > ( > [5319] => 59ad2597-807c-441b-89ef-01bb94fbc969 > ) > > [del] => Array > ( > [5318] => 59ad2597-807c-441b-89ef-01bb94fbc969 > ) > > ) > [pid 25876 on line 351 of > "/usr/share/php/Horde/Kolab/Storage/Data/Base.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Incremental Horde_History update for user: > m.gabriel@das-netzwerkteam.de, folder: INBOX/Kalender, prefix: > kronolith:YTozOntpOjA7czoyOToibS5nYWJyaWVsQGRhcy1uZXR6d2Vya3RlYW0uZGUiO2k6MTtzOjg6IkthbGVuZGVyIjtpOjI7czo1OiJJTkJPWCI7fQ: [pid 25876 on line 73 of > "/usr/share/php/Horde/Kolab/Storage/Data/Query/History/Cache.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Modifying object in Horde_History: > kronolith:YTozOntpOjA7czoyOToibS5nYWJyaWVsQGRhcy1uZXR6d2Vya3RlYW0uZGUiO2k6MTtzOjg6IkthbGVuZGVyIjtpOjI7czo1OiJJTkJPWCI7fQ:59ad2597-807c-441b-89ef-01bb94fbc969, uid: 5319, force: 0 [pid 25876 on line 127 of > "/usr/share/php/Horde/Kolab/Storage/Data/Query/History/Base.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Object still existing: object: 59ad2597-807c-441b-89ef-01bb94fbc969, > vanished IMAP uid: 5318. Skipping delete from Horde_History. [pid > 25876 on line 73 of > "/usr/share/php/Horde/Kolab/Storage/Data/Query/History/Cache.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] Modified data > object 59ad2597-807c-441b-89ef-01bb94fbc969 in INBOX/Kalender. [pid > 25876 on line 409 of > "/usr/share/horde/kronolith/lib/Driver/Kolab.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE [kronolith] INBOX/Kalender has > 30 objects [too many to list]. [pid 25876 on line 114 of > "/usr/share/horde/kronolith/lib/Driver/Kolab.php"] > 2019-05-12T01:41:01+02:00 ERR: HORDE [kronolith] SQL QUERY FAILED: > Duplicate entry '59ad2597-807c-441b-89ef-01bb94fbc969' for key > 'index_horde_dav_objects_on_id_internal' > INSERT INTO horde_dav_objects (id_internal, id_external, > id_collection) VALUES ('59ad2597-807c-441b-89ef-01bb94fbc969', > '59ad2597-807c-441b-89ef-01bb94fbc969.ics', > 'YTozOntpOjA7czoyOToibS5nYWJyaWVsQGRhcy1uZXR6d2Vya3RlYW0uZGUiO2k6MTtzO > jg6IkthbGVuZGVyIjtpOjI7czo1OiJJTkJPWCI7fQ') [pid 25876 on line 318 > of "/usr/share/php/Horde/Db/Adapter/Mysqli.php"] > 2019-05-12T01:41:01+02:00 DEBUG: HORDE Max memory usage: 2097152 > bytes [pid 25876 on line 613 of "/usr/share/php/Horde/Registry.php"] > ``` > > ... and some look like this: > > ``` > 2019-05-11T23:40:42+00:00 DEBUG: HORDE Load config file (conf.php; > app: horde) [pid 17266 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:40:42+00:00 DEBUG: HORDE Load config file (nls.php; > app: horde) [pid 17266 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:40:42+00:00 DEBUG: HORDE [horde] Horde_Rpc::__construct > complete [pid 17266 on line 45 of > "/usr/share/php/Horde/Rpc/Webdav.php"] > 2019-05-11T23:40:42+00:00 DEBUG: HORDE Horde_Rpc::authorize() > starting [pid 17266 on line 137 of "/usr/share/horde/rpc.php"] > 2019-05-11T23:40:42+00:00 DEBUG: HORDE Load config file (prefs.php; > app: horde) [pid 17266 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:40:42+00:00 DEBUG: HORDE Load config file (conf.php; > app: horde) [pid 17266 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:40:42+00:00 DEBUG: HORDE Load config file (conf.php; > app: ) [pid 17266 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:40:42+00:00 DEBUG: HORDE [kronolith] Load config file > (conf.php; app: kronolith) [pid 17266 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-11T23:40:42+00:00 DEBUG: HORDE [kronolith] Load config file > (prefs.php; app: kronolith) [pid 17266 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieving namespaces. [pid 17266 > on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieved namespaces > [Horde_Kolab_Storage_Folder_Namespace_Imap: "INBOX" (personal, "/"), > "user" (other, "/"), "" (shared, "/")]. [pid 17266 on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] REQUEST OUT IMAP: > 0 ms [getNamespace] [pid 17266 on line 276 of > "/usr/share/php/Horde/Kolab/Storage/List/Tools.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieving namespaces. [pid 17266 > on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieved namespaces > [Horde_Kolab_Storage_Folder_Namespace_Imap: "INBOX" (personal, "/"), > "user" (other, "/"), "" (shared, "/")]. [pid 17266 on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] REQUEST OUT IMAP: > 0 ms [getNamespace] [pid 17266 on line 276 of > "/usr/share/php/Horde/Kolab/Storage/List/Tools.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieving namespaces. [pid 17266 > on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] Driver > "Horde_Kolab_Storage_Driver_Imap": Retrieved namespaces > [Horde_Kolab_Storage_Folder_Namespace_Imap: "INBOX" (personal, "/"), > "user" (other, "/"), "" (shared, "/")]. [pid 17266 on line 310 of > "/usr/share/php/Horde/Kolab/Storage/Driver/Decorator/Base.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] REQUEST OUT IMAP: > 0 ms [getNamespace] [pid 17266 on line 276 of > "/usr/share/php/Horde/Kolab/Storage/List/Tools.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] Load config file > (prefs.php; app: horde) [pid 17266 on line 109 of > "/usr/share/php/Horde/Registry/Loadconfig.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Fetching stamp WITH token. [pid 17266 on line 252 of > "/usr/share/php/Horde/Kolab/Storage/Data/Cached.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] Synchronized data > cache for INBOX/Kalender. [pid 17266 on line 63 of > "/usr/share/php/Horde/Kolab/Storage/Synchronization/OncePerSession.php"] > 2019-05-12T01:40:42+02:00 DEBUG: HORDE [kronolith] INBOX/Kalender has > 30 objects [too many to list]. [pid 17266 on line 114 of > "/usr/share/horde/kronolith/lib/Driver/Kolab.php"] > 2019-05-12T01:40:43+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Fetching stamp WITH token. [pid 17266 on line 252 of > "/usr/share/php/Horde/Kolab/Storage/Data/Cached.php"] > 2019-05-12T01:40:43+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Incremental folder sync: user: m.gabriel@das-netzwerkteam.de, folder: > INBOX/Kalender, last_sync: 1557618042, current_sync: 1557618043, > changes: Array > ( > [add] => Array > ( > [5312] => 2B0D064A-CE3C-4125-B8FF-93A0AD004305 > ) > > [del] => Array > ( > [5246] => 2B0D064A-CE3C-4125-B8FF-93A0AD004305 > ) > > ) > [pid 17266 on line 351 of > "/usr/share/php/Horde/Kolab/Storage/Data/Base.php"] > 2019-05-12T01:40:43+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Incremental Horde_History update for user: > m.gabriel@das-netzwerkteam.de, folder: INBOX/Kalender, prefix: > kronolith:YTozOntpOjA7czoyOToibS5nYWJyaWVsQGRhcy1uZXR6d2Vya3RlYW0uZGUiO2k6MTtzOjg6IkthbGVuZGVyIjtpOjI7czo1OiJJTkJPWCI7fQ: [pid 17266 on line 73 of > "/usr/share/php/Horde/Kolab/Storage/Data/Query/History/Cache.php"] > 2019-05-12T01:40:43+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Modifying object in Horde_History: > kronolith:YTozOntpOjA7czoyOToibS5nYWJyaWVsQGRhcy1uZXR6d2Vya3RlYW0uZGUiO2k6MTtzOjg6IkthbGVuZGVyIjtpOjI7czo1OiJJTkJPWCI7fQ:2B0D064A-CE3C-4125-B8FF-93A0AD004305, uid: 5312, force: 0 [pid 17266 on line 127 of > "/usr/share/php/Horde/Kolab/Storage/Data/Query/History/Base.php"] > 2019-05-12T01:40:43+02:00 DEBUG: HORDE [kronolith] [KOLAB_STORAGE] > Object still existing: object: 2B0D064A-CE3C-4125-B8FF-93A0AD004305, > vanished IMAP uid: 5246. Skipping delete from Horde_History. [pid > 17266 on line 73 of > "/usr/share/php/Horde/Kolab/Storage/Data/Query/History/Cache.php"] > 2019-05-12T01:40:43+02:00 DEBUG: HORDE [kronolith] Modified data > object 2B0D064A-CE3C-4125-B8FF-93A0AD004305 in INBOX/Kalender. [pid > 17266 on line 409 of > "/usr/share/horde/kronolith/lib/Driver/Kolab.php"] > 2019-05-12T01:40:43+02:00 DEBUG: HORDE [kronolith] INBOX/Kalender has > 30 objects [too many to list]. [pid 17266 on line 114 of > "/usr/share/horde/kronolith/lib/Driver/Kolab.php"] > 2019-05-12T01:40:43+02:00 DEBUG: HORDE Max memory usage: 2097152 > bytes [pid 17266 on line 613 of "/usr/share/php/Horde/Registry.php"] > ``` >
Attachment
Watch this ticket
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