Closed Bug 1106727 Opened 9 years ago Closed 8 years ago

Lightning stopped sync with OwnCloud calendar

Categories

(Calendar :: Provider: CalDAV, defect)

Lightning 3.3
x86
Windows 7
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: office, Unassigned)

Details

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:33.0) Gecko/20100101 Firefox/33.0
Build ID: 20141106120505

Steps to reproduce:

Upgraded TB and Lightning to latest version.
TB: 31.3.0
Lightning: 3.3.1

No other things changed! 


Actual results:

Lightning suddenly stopped sync calendar with OwnCloud!

A few additional informations:
* Creating an new appointment within Lightning => appointment is synced with OwnCloud
* Deleting the appointment in OwnCloud => it's also deleted in Lightning
* Creating new appointment in OwnCloud => it's NOT transferred to Lightning
* Download of existing appointments from OwnCloud calendar => FAILED

PHP-Version of Webserver: 5.3.29
OwnCloud Version: 7.0.3

****
Statement from my webhoster:

I did some looking around and the only thing that jumped out at me was where the "CalDAV-Sync" user agent requests in the logs was issuing a 'REPORT' request and that in turn led to a '500' internal server error...

I see that SabreDAV 1.8.10 supports PHP 5.3, but I'm not sure how well it supports PHP 5.5 yet...  You may want to bring your site down to PHP 5.3 to test...
http://sabre.io/dav/install/

Overall, this is a 3rd party script problem and there is only so much we can do...  I don't see any segfaults or any other anomalies that would explain this from the server level...

Please contact the script's author and see if they can help with turning on debugging which may help isolate exactly where the problem is...
*****


Expected results:

---
OS: All → Windows 7
Hardware: All → x86
You could ask your provider for more log entries. A "internal server" error is just a "generic error" where the reason should be logged somewhere in the webservers error log or the error log of PHP.
I have this issue as well. Since a few weeks Thunderbird/Lightning does not sync with ownCloud/nextcloud anymore. I don't know what changed in the meantime. The Problem appears on the most recent TB/Lightning on Windows 10. As well as on Kubuntu 16.04LTS.

According to the hosting provider the issue might be connected with the http2 protocoll.

As it works with Android and iOS devices I suspect there must be something Lightning does differently and fails.

The TB error console gives the following errors
Zeitstempel: 21.07.2016 16:01:05
Fehler: [calCachedCalendar] replay action failed: null, uri=https://cloud.domain.tld/remote.php/dav/calendars/user/defaultcalendar/, result=2147500037, op=[xpconnect wrapped calIOperation]
Quelldatei: file:///C:/Users/user/AppData/Roaming/Thunderbird/Profiles/ovwaor4h.default/extensions/%7Be2fda1a4-762b-4020-b5ad-a41df1933103%7D/calendar-js/calCachedCalendar.js
Zeile: 327
I just go the information from my provider (Hostpoint) that they upgraded from Apache 2.2 to 2.4 which is now also supporting http2. So it was this change that broke the calendar sync with ownCloud/nextcloud.
Please enable calendar.debug.log and calendar.debug.log.verbose in the config editor and check for new messages after a restart. From what I read this seems to be an http2 issue and not specific to Lightning? I'm closing this as incomplete for now, if there is something that can be done in Lightning I am happy to reconsider.

Please also take some time to find the regeression range. Does this work with older versions of Thunderbird+Lightning?
Status: UNCONFIRMED → RESOLVED
Closed: 8 years ago
Resolution: --- → INCOMPLETE
I had the exact same problem. Removing http2 support from the web server solved the issue. So that's definitely related to using http2.
And it's not specific to owncloud as another reverse proxied calendar (not using owncloud but reverse proxied on the same http2 web server) also has exactly the same issue.
Good to hear that I'm not alone with this issue! Unfortunately I can't (yet) disable http2 at Hostpoint. Be they sad they are working on a option, making this possible.
(In reply to Philipp Kewisch [:Fallen] from comment #6)
> Please enable calendar.debug.log and calendar.debug.log.verbose in the
> config editor and check for new messages after a restart. From what I read
> this seems to be an http2 issue and not specific to Lightning? I'm closing
> this as incomplete for now, if there is something that can be done in
> Lightning I am happy to reconsider.
> 
> Please also take some time to find the regeression range. Does this work
> with older versions of Thunderbird+Lightning?

What's the best way to get the error into a text file? In the error console I can only copy one message after the other which is quite cumbersome.
Side note: Thunderbird + Lightning works here since longer time on Linux and Windows Clients against an ownCloud installation without any of such issues. Previously i had used nginx + php-fpm with SPDY (previously) and HTTP/2 (now). As Apache was mentioned maybe this is just because you're using mod_php and its not a bug in Lightning:

> If you are using mpm_prefork, the default is *one* worker per process. Increasing the number may be unsafe if you also use non-thread-safe modules such as mod_php. This can break certain workflows, because requests which would previously have gone to a separate worker - such as asynchronous updates during a long-running submit - are delayed until the client's initial request has completed (Bug 60244). To avoid this, you need to switch to e.g. mod_event and PHP-FPM.

-> From the comments in https://httpd.apache.org/docs/2.4/mod/mod_http2.html
> Previously i had used nginx + php-fpm with SPDY (previously) and HTTP/2 (now).

Sorry, can't edit this. Actually i mean:

I'm using nginx + php-fpm with SPDY (previously) and HTTP/2 (now).

Additional note:

That you shouldn't use SPDY/HTTP2 with mod_php is widely documented, e.g. on:

https://developers.google.com/speed/spdy/mod_spdy/php

I think its more likely this issue here with mod_php rather then with Lightning.
(In reply to Philipp Kewisch [:Fallen] from comment #6)
> Please enable calendar.debug.log and calendar.debug.log.verbose in the
> config editor and check for new messages after a restart. From what I read
> this seems to be an http2 issue and not specific to Lightning? I'm closing
> this as incomplete for now, if there is something that can be done in
> Lightning I am happy to reconsider.
Here you can find parts of the error log http://pastebin.com/H9UBvjFM
Please note:
* it contains data for two calendars only (I have more configured), one which works fine "Company (Kolab)" using http/1.1 and one that does not work "Privat (nextcloud)" using HTTP/2.0.
* The log might not be complete as I had to manually copy every single message and only did for the ones which seemed relevant to me. If something crucial is missing, I'll gladly provide more.
* all private data such as usernames, URLs, etc have been changed anonymous values.

> Please also take some time to find the regeression range. Does this work
> with older versions of Thunderbird+Lightning?
As stated above, it stopped working on updating to Apache 2.4 with http2 enabled. Before it was working fine for many years. I don't know how I could test it with older versions.
(In reply to chris from comment #11)
> I think its more likely this issue here with mod_php rather then with
> Lightning.
All my other clients work fine, only TB/Lightning doesn't!
BTW: The web server log shows a negotiation error. This is possible connected to the issue. Client IP address changed to anonymous value.

[Sat Dec 10 15:21:00.449931 2016] [negotiation:error] [pid 4461:tid 34681419776] [client 123.123.123.123:36005] AH00690: no acceptable variant: /usr/local/www/apache24/error/HTTP_LENGTH_REQUIRED.html.var
[Sat Dec 10 15:21:00.532142 2016] [negotiation:error] [pid 4461:tid 34654109696] [client 123.123.123.123:36005] AH00690: no acceptable variant: /usr/local/www/apache24/error/HTTP_LENGTH_REQUIRED.html.var
[Sat Dec 10 15:38:06.332480 2016] [negotiation:error] [pid 4461:tid 34681446400] [client 123.123.123.123:12545] AH00690: no acceptable variant: /usr/local/www/apache24/error/HTTP_LENGTH_REQUIRED.html.var
[Sat Dec 10 15:38:06.401779 2016] [negotiation:error] [pid 4461:tid 34654120960] [client 123.123.123.123:12545] AH00690: no acceptable variant: /usr/local/www/apache24/error/HTTP_LENGTH_REQUIRED.html.var
[Sat Dec 10 16:08:03.880734 2016] [negotiation:error] [pid 4471:tid 34681417728] [client 123.123.123.123:58147] AH00690: no acceptable variant: /usr/local/www/apache24/error/HTTP_LENGTH_REQUIRED.html.var
[Sat Dec 10 16:08:03.925796 2016] [negotiation:error] [pid 4471:tid 34681417728] [client 123.123.123.123:58147] AH00690: no acceptable variant: /usr/local/www/apache24/error/HTTP_LENGTH_REQUIRED.html.var
Lightning didn't work with a davmail calendar using nginx with http2 as a reverse proxy. So no PHP involved here, only nginx with http2.
As others mentioned, other clients are working fine, but maybe not using http2.
So the issue might be with nginx+http2 or lightning.
(In reply to Philipp Kewisch [:Fallen] from comment #6)
> I'm closing
> this as incomplete for now, if there is something that can be done in
> Lightning I am happy to reconsider.

Please do reopen the bug. There is definitely something wrong with TB/Lightning.
This does not look like a TB/Lightning issue, even if you're expiriencing it only with this client. Our OPTIONS request is serverside responded by 411 (=HTTP_LENGTH_REQUIRED) which is pointless because the OPTIONS request has no body (=content) at all. Also, the RfC [1] does not require to specify the length of the request (other then that of the response). This this might either be a configuration issue or a bug of the webserver.

To dig further into that issue, you can try to send an OPTIONS request to your server using cURL and see whether you can manually work around the problem by adding content-headers (if you add a content-length, you would also need to specify the content-type), although I don't think it will work.

Another option might be to inpsect the communication using wireshark to see whether the request does contain anything unexpected (if so, this would be a toolkit bug then).

And finally, you can try to work around by playing with the Thunderbird network.http.spdy.* preferences in the config editor. Maybe clientside disabling makes your Owncloud sync again.

[1] https://tools.ietf.org/html/rfc7231#section-4.3.7
FYI: This is indeed a bug on the server side. I can reproduce it with Apache 2.4.25 with the http2 module enabled. The server replies with a 411 and doesn't actually pass the OPTIONS request on to the application.

Disabling network.http.spdy.enabled.http2 works around the problem.
It would be great if Thunderbird could send "Content-Length: 0". 

Whether this is actually a SHOULD requirement in RFC7230 is unclear to me. Reading the RFC:

https://tools.ietf.org/html/rfc7230#section-3.3.2 specifies that:

   A user agent SHOULD send a Content-Length in a request message when
   no Transfer-Encoding is sent and the request method defines a meaning
   for an enclosed payload body.  For example, a Content-Length header
   field is normally sent in a POST request even when the value is 0
   (indicating an empty payload body).  A user agent SHOULD NOT send a
   Content-Length header field when the request message does not contain
   a payload body and the method semantics do not anticipate such a
   body.

OPTIONS could contain a payload body according to RFC7230 section 4.3.7, but it doesn't define a meaning:

   A client that generates an OPTIONS request containing a payload body
   MUST send a valid Content-Type header field describing the
   representation media type.  Although this specification does not
   define any use for such a payload, future extensions to HTTP might
   use the OPTIONS body to make more detailed queries about the target
   resource.
SHOULD is actually defined exactly in rfc 2119. As we are using the Mozilla Platform for our network requests I think it is reasonable not to do this, but I'm sure we could add a hack to do so. I'd rather prefer the server handling this correctly though, because SHOULD for server implementers actually means "anticipate that clients won't always do this".
I can confirm that setting network.http.spdy.enabled.http2 to false brought back my calendar sync!
FWIW I've filed a bug about the server here: https://bz.apache.org/bugzilla/show_bug.cgi?id=60663, though it would still be nice if the client could also add a hack to send "Content-Length: 0".
You need to log in before you can comment on or make changes to this bug.