[horde] Unable to synchronize calendar with Horde Groupware 5.2.22 and Thuderbird 60.4.0

Wed Feb 20 20:47:28 UTC 2019

Hi, Jan.

On 20/2/19 09:19, Jan Schneider wrote:

>>>>> I am being unable to synchronize my calendar in Horde with Thunderbird
>>>>> 60.4.0. It's strange because I see that it brought all the events I
>>>>> had
>>>>> but still Thunderbird shows a triangle with an exclamation mark saying
>>>>> "The calendar is momentarily not available".
>>>>>
>>>>> It's weird because it brought the information from Horde calendar
>>>>> and in
>>>>> fact I added a new event in Thunderbird and it was shown by Horde. But
>>>>> when I pressed the sync button this message was shown with an
>>>>> exclamation mark.
>>>>>
>>>>> Recently I upgraded from Debian Jessie to Debian Stretch, but I was
>>>>> already experiencing this problem since Debian Jessie.
>>>>>
>>>>> With the previous version of Thunderbird I think I didn't have this
>>>>> problem. I would like to be able to provide more information to help
>>>>> with the debug. If you know of anything else I can add to find the
>>>>> cause
>>>>> of the problem, please let me know.
>>>>>
>>>>> I'm using Horde Groupware 5.2.22.

>>>> Today I added a contact in the address book and it has not been
>>>> synchronized either. Is it possible that it is due to the same problem?
>>>>
>>>> Jan, Mike: Could you suggest some way to debug the issue?

>>> I've got some more information that can be more enlightening.
>>>
>>> I've set the following 2 preferences in Config Editor:
>>>
>>> calendar.debug.log true
>>> calendar.debug.verbose.log true
>>>
>>> After restart Thunderbird and check the Error Console I got some
>>> synchronization errors. Some of the lines that I have identified are
>>> these:
>>>
>>> ----------
>>> Lightning:CalDAV: Get failed: CalDAV: Error: got status 404 fetching
>>> calendar data for Daniel Bareiro (Horde), null  calDavCalendar.js:1221
>>>
>>> (...)
>>>
>>> Lightning:There has been an error reading data for calendar: Daniel
>>> Bareiro (Horde).  However, this error is believed to be minor, so the
>>> program will attempt to continue. Error code: 0x80004005. Description:
>>> CalDAV: Error: got status 404 fetching calendar data for Daniel Bareiro
>>> (Horde), null  calCalendarManager.js:984
>>>
>>> (...)
>>>
>>> Lightning:There has been an error reading data for calendar: Daniel
>>> Bareiro (Horde).  However, this error is believed to be minor, so the
>>> program will attempt to continue. Error code: READ_FAILED. Description:
>>>   calCalendarManager.js:984
>>>
>>> Lightning:CalDAV: recv: null  calDavRequestHandlers.js:754
>>> ----------
>>>
>>> The full output is a little long so I have placed it in an attachment.
>>>
>>> I would appreciate any advice.

>> Here some more information. I was checking the Apache logs to see the
>> entries I found when I clicked on "Synchronize Calendars" from
>> Thunderbird:
>>
>> ----------
>> 10.1.0.40 - mailuser [18/Feb/2019:18:29:26 -0300] "PROPFIND
>> /rpc.php/calendars/mailuser/tasks%3A12A21iCQ-1ivBlQQUNhO-Q6/ HTTP/1.1"
>> 207 1464 "-" "Mozilla/5.0 (X11; Linu
>> x x86_64; rv:60.0) Gecko/20100101 Thunderbird/60.5.1 Lightning/6.2.5.1"
>> 10.1.0.40 - mailuser [18/Feb/2019:18:29:26 -0300] "PROPFIND
>> /rpc.php/calendars/mailuser/calendar~aYSRwQTd_MgwlYQVH5h_Vw1/ HTTP/1.1"
>> 207 21974 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101
>> Thunderbird/60.5.1 Lightning/6.2.5.1"
>> 10.1.0.40 - mailuser [18/Feb/2019:18:29:28 -0300] "REPORT
>> /rpc.php/calendars/mailuser/calendar~aYSRwQTd_MgwlYQVH5h_Vw1/ HTTP/1.1"
>> 404 830 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101
>> Thunderbird/60.5.1 Lightning/6.2.5.1"
>> ----------
>>
>> I'm not sure why it is returning a 404 in the REPORT since the CalDAV
>> Subscription URL is correct

> Do you see anything in the Horde logs when this happens?

I think Horde is using syslog according to the configuration:

----------
# grep log conf.php
(...)
$conf['log']['priority'] = 'INFO';
$conf['log']['ident'] = 'HORDE';
$conf['log']['name'] = LOG_USER;
$conf['log']['type'] = 'syslog';
$conf['log']['enabled'] = true;
(...)
----------

So I was checking the syslog to see what entries are added after
clicking on 'synchronize calendars', but only are shown entries for
Cyrus rather than for Horde:

----------
Feb 20 17:31:32 mail cyrus/imap[28043]: inittls: Loading hard-coded DH
parameters
Feb 20 17:31:32 mail cyrus/imap[28043]: starttls: TLSv1.2 with cipher
ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits new) no authentication
Feb 20 17:31:32 mail cyrus/imap[28043]: login: localhost [::1] mailuser
PLAIN+TLS User logged in
SESSIONID=<cyrus-28043-1550694692-1-15800520922996795473>
Feb 20 17:31:32 mail cyrus/imap[28043]: USAGE mailuser user: 0.052000
sys: 0.020000
Feb 20 17:31:32 mail cyrus/imap[28043]: starttls: TLSv1.2 with cipher
ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits new) no authentication
Feb 20 17:31:32 mail cyrus/imap[28043]: login: localhost [::1] mailuser
PLAIN+TLS User logged in
SESSIONID=<cyrus-28043-1550694692-2-12352046232787961396>
Feb 20 17:31:33 mail cyrus/imap[28043]: USAGE mailuser user: 0.024000
sys: 0.004000
Feb 20 17:31:33 mail cyrus/imap[28044]: inittls: Loading hard-coded DH
parameters
Feb 20 17:31:33 mail cyrus/imap[28044]: starttls: TLSv1.2 with cipher
ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits new) no authentication
Feb 20 17:31:33 mail cyrus/imap[28044]: login: localhost [::1] mailuser
PLAIN+TLS User logged in
SESSIONID=<cyrus-28044-1550694693-1-18348973881061009573>
Feb 20 17:31:33 mail cyrus/imap[28044]: USAGE mailuser user: 0.060000
sys: 0.020000
----------

Maybe I should change 'priority' to 'DEBUG'?

Thanks for your time.

Kind regards,
Daniel

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 195 bytes
Desc: OpenPGP digital signature
URL: <https://lists.horde.org/archives/horde/attachments/20190220/d3c7a0eb/attachment.bin>