992340 - Synchronizing CalDAV calendar from owncloud (https) fails, when using SSL with unsigned certificate

Status: RESOLVED WORKSFORME

(Calendar :: Lightning Only, defect)

Description

[spam]

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:28.0) Gecko/20100101 Firefox/28.0 (Beta/Release)
Build ID: 20140314220517

Steps to reproduce:

- Create a calendar on an owncloud server.
- Add the calendar to lightning by using the link:
http://mydomain:60080/owncloud/remote.php/caldav/calendars/myusername/defaultcalendar
- enable offline synchronization and enter username and password
- Add the calendar to lightning by using the link:
https://mydomain:60443/owncloud/remote.php/caldav/calendars/myusername/defaultcalendar
- accept the certificate, enable offline synchronization and enter username and password


Actual results:

- Adding the calendar to lightning by using the link:
http://mydomain:60080/owncloud/remote.php/caldav/calendars/myusername/defaultcalendar works, including synchronization and offline cache
- Adding the calendar to lightning by using the link:
https://mydomain:60443/owncloud/remote.php/caldav/calendars/myusername/defaultcalendar works, but no entries show up and if entries are added to lightning, they don't get pushed to the server. If offline synchronization is disabled, synchronization never terminates but no error is shown.


Expected results:

The ssl connection should behave the same as the non-ssl-connection. Using the SSL variant works with android phone, so the provider is usable in both cases.

Comment 1

[Stefan Sitter [:ssitter]]

I have seen similar reports for ownCloud. For this users HTTPS connection worked after disabling SPDY in the ownCloud settings.

Comment 2

[spam]

Thanks for the hint, I will try that and report back ...

Comment 3

[spam]

This indeed did the trick, thanks a lot for your help.

Comment 4

[u504086]

Sounds like a similar problem to what I am experiencing.

Forgive me for being thick, but I cannot find anywhere to disable SPDY. What is SPDY anyway?
Thanks!

Comment 5

[u504086]

Tip worked for me as well! :)
Thanks!

Comment 6

[spam]

(In reply to oyvind.siegesmund from comment #4)
> Sounds like a similar problem to what I am experiencing.
> 
> Forgive me for being thick, but I cannot find anywhere to disable SPDY. What
> is SPDY anyway?
> Thanks!

SPDY shall speed up SSL-connections if I'm not mistaken. Since I'm using owncloud on my synology, I just had to untick a box to disable it. Without further information about your setup, no one will be able to tell you what to do.

Comment 7

[spam]

Actually google told me it "replaces" http and uses tls as default.

Comment 8

[u422471]

Hi,

are you using Apache with mod_php? Then please note the statement here:

---------------------------------------------------------------------------------------------------------
Much like the Apache Worker MPM, mod_spdy is a multithreaded module, and processes multiple SPDY requests from the same connection simultaneously. This poses a problem for other Apache modules that may not be thread-safe, such as mod_php. Fortunately, it is fairly easy to adjust your Apache configuration to make your existing PHP code safe to use with mod_spdy (and with the Worker MPM as well).
---------------------------------------------------------------------------------------------------------

and switch to mod_fcgi as described in:

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

Comment 9

[spam]

Since my mobile phone had no issues to synchronize in the very same setup, I doubt that this is the reason for this issue. I will check nevertheless and report back as soon as I know what the Synology is doing.

Comment 10

[u422471]

Mhhh, have running Thunderbird 24.5.0 on Win 8.1, Debian testing and Win 7 syncing with Lightning 2.6.4 to ownCloud 6.0.3 on a NginX 1.6.0/php-fpm 5.4.x server (SPDY enabled) and don't see any issues like this.

Comment 11

[thorkhas]

I had the same bug : 
- using lightning 2.6.5 on Windows, Ubuntu linux 
- trying to sync with owncloud
- owncloud was hosted by a Synology NAS with DSM 5.0 -- bug appeared after the upgrade to 5.0
- using self-signed certificate

Disabling SPDY did the trick.

This bug may be specific to that configuration : synology DSM 5.0 with SPDY enabled, owncloud.

Comment 12

[Stefan Sitter [:ssitter]]

Resolving as WFM per comment 3 and comment 11.

Comment 13

[slalomsk8er]

Bug still exists in Lightning as I didn't need to disable SPDY on my synology DSM for KOrganizer to work.
Thanks for ignoring the Bug since months it just cost me 4 hours to find the "solution" on the Web as the logs were useless. Please provide at least a error massage if sync fails!

Comment 15

[[:MakeMyDay]]

Ranting doesn't catalyse anything...

Based on your report of bug 992340, this is still an issue in 3.3.2. Are you on a custom spdy configuration (look for bold entries for network.http.spdy.* in config editor)?

Is the server accessible with Firefox (and the same spdy config)?

Can you please enable calendar.debug.log, calendar.debug.log.verbose and javascript.options.showInConsole in config editor and post any related log message while reproducing with your setup? Then, in a second run, what messages do you get, if you disable caching for the respective calendar?

Can you also provide the corresponding server log files?

Comment 16

[slalomsk8er]

Ranting has it's place as you now know that it can cost a user time and there is an error in the error reporting ;)

I have no changes in the SPDY config.
I need to do more research to find the server logs.
I will attach the logs.

Comment 17

[slalomsk8er]

Attachment: log1.txt

Comment 18

[slalomsk8er]

Attachment: log2.txt

Comment 19

[[:MakeMyDay]]

Lightning is maintained by volunteers only and nobody will get motivated to invest his/her spare time to solve your problem by statements like in comment #13, esp. if this is your very first posting on bugzilla - so ranting doesn't has its place for no reason here.

This prepended, your logs indicate the server responds with a 405 error on the OPTIONS request on the current-user-principal url. Based on the previous comments on this bug, this works with speedy disabled, so this behaviour has its root cause either in Owncloud or (more likely) the SPDY implementation of the webserver respectively its configuration.

So to really fix this, it needs action on the server end. Eventually your server logs provide more information about where to look there. But maybe extending an existing workaround in Lightning for another server-side problem (bug 588799) can resolve this, too. If you want to give it a try, do the following:

1. go to [extension folder in your TB profile]/{e2fda1a4-762b-4020-b5ad-a41df1933103}/components
2. create a backup of calDavCalendar.js
3. open calDavCalendar.js and change line (assuming you're on 3.3.x) 1889 from
>                if (!calHomeSetUrlRetry && request.responseStatus == 404) {
to
>                if (!calHomeSetUrlRetry && (request.responseStatus == 404 || request.responseStatus == 405)) {
4. save the changes, restart TB and give it a try.
5. replace the modified calDavCalendar.js by the original one if this doesn't work
6. report back about the result

Comment 20

[slalomsk8er]

It didn't work:

CalDAV: initial ctag 74 for calendar test1
Adding supported items: VEVENT,VTODO for calendar: test1
CalDAV: Found principal url from DAV:current-user-principal /owncloud/remote.php/caldav/principals/504efbaa-0212-1033-8fae-21da66df941f/
CalDAV: send: OPTIONS https://192.168.1.2/owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/
CalDAV: Calendar homeset was not found at parent url of calendar URL while querying options test1, will try calendar URL itself now
CalDAV: send: OPTIONS https://192.168.1.2/owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/defaultcalendar/
CalDAV: Unexpected status 405 while querying options test1
1420283824389   addons.update-checker   WARN    Update manifest for {972ce4c6-7e08-4474-a285-3208198ce6fd} did not contain an updates property

Comment 21

[slalomsk8er]

I'm still digging around and it appears like I can upload events if I reactivate SPDY.
Downloading events on the other hand doesn't work.
Also edits on the server don't get pulled.

Comment 22

[[:MakeMyDay]]

Until here this indicates that PROPFIND and PUT requests are working well while at least OPTIONS requests don't. Maybe the serverlogs indicate what the problem is. Good candidates are the webserver access and error logs, the syslog and the owncloud application log - if any. Maybe you need to modify the debug level to see anything related.

Additionally, you might want to check what the server replies on the OPTIONS request with SPDY disabled.

Comment 23

[slalomsk8er]

I found a way to enable logging on the DiskStation.

192.168.1.100 - - [03/Jan/2015:13:17:51 +0100] "PROPFIND /owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/defaultcalendar/ HTTP/1.1" 207 528 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.3.0 Lightning/3.3.2" 
192.168.1.100 - - [03/Jan/2015:13:17:52 +0100] "OPTIONS /owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/ HTTP/1.1" 405 127 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.3.0 Lightning/3.3.2"

Comment 24

[slalomsk8er]

This is how it looks without SPDY:

192.168.1.100 - - [03/Jan/2015:13:34:14 +0100] "PROPFIND /owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/defaultcalendar/ HTTP/1.1" 207 528 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.3.0 Lightning/3.3.2"
192.168.1.100 - - [03/Jan/2015:13:34:15 +0100] "OPTIONS /owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/ HTTP/1.1" 200 25 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.3.0 Lightning/3.3.2"
192.168.1.100 - - [03/Jan/2015:13:34:15 +0100] "PROPFIND /owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/defaultcalendar/ HTTP/1.1" 207 1789 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.3.0 Lightning/3.3.2"
192.168.1.100 - - [03/Jan/2015:13:34:15 +0100] "REPORT /owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/defaultcalendar/ HTTP/1.1" 207 5169 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.3.0 Lightning/3.3.2"

Comment 25

[[:MakeMyDay]]

These are access logs, which just confirm what you already know from the TB logs. What you need is the error logging, eventually on debug level and the apllication logging of owncloud, also at best on debug level to get a grip why the OPTIONS request fails.

Comment 26

[slalomsk8er]

There is nothing in the ownCloud log even on debug concerning the request from TB.
I will attach the apache debug log but I fear it is also useless.

Comment 27

[u422471]

Hi,

have you also checked this:

https://bugzilla.mozilla.org/show_bug.cgi?id=992340#c8

No idea if this will fix those issues but i think it could be useful to check if Synology is shipping mod-php.

Comment 28

[slalomsk8er]

Attachment: debug_log

Comment 29

[slalomsk8er]

@chris

Yes that workaround works but doesn't fix the problem that Thunderbird doesn't work out of the box like CalDAV for Android and KOrganizer and needs changes to default settings on the server. The other problem is that it fails silently.

Comment 30

[u422471]

@slalomsk8er
Your posted debug_log shows that your Synology is running php-fpm so my comment shouldn't be relevant in this case.

Comment 31

[[:MakeMyDay]]

Indead, the server log doesn't provide any hints.

Have you already opened a bug against Synology for this issue? Based on comment #10 of Chris, this works with a different webserver, so the Apache/SPDY implementation/configuration is suspicious here. An OPTIONS request on the current-user-principial ressource is a common approach and proved to be working with owncloud if SPDY is disabled - so this should not end in a 405 response from the server. And for the Lightning code at this stage - the request is transparent, whether SPDY is used or not.

Maybe a manual request via curl can highlight some more information, that can also be used to report to Synology/Apache/Google:

>curl -vk -u user:password -X OPTIONS https://{yourServer}/owncloud/remote.php/caldav/calendars/504efbaa-0212-1033-8fae-21da66df941f/

Beside that and just for curiousity, what does show up in the apache access log, if you perform the sucessfull sync with the other clients while SPDY is enabled?

Comment 32

[bugzilla.mozilla.org]

I just ran in to this bug with the following configuration:
**Operating system**:
Raspbian (Debian wheezy)
**Web server:**
Nginx 1.6.2
**PHP version:**
5.4.36-0+deb7u3 (php-fpm)
**ownCloud version:**
8.0 (stable) fresh install

**Client**
Firefox 35.0.1 on Windows 7 64-bit

I can't login to Owncloud with spdy suppport in Nginx.
I can login to Owncloud without spdy support in Nginx
I can login to Owncloud with spdy in Nginx and firefox about:config network.http.spdy.enabled.v3-1 set to false.

As the problem is now with multiple servers (Apache and Nginx).
My guess it's in the 3.1 part of spdy in Firefox.

Will search further and try to enable some debug logging (as all logging (Nginx access and error, Syslog, PHP, Owncloud) does not show anything relevant.

Comment 33

[Philipp Kewisch [:Fallen][📱📆]]

You say Firefox, could you report this over in the Core/Networking component? This bug is about Lightning, and the actual fix was in the core. Please try a nightly build first, it might not be fixed on Firefox 35 yet.

I also think we can close this one, the spdy issue was fixed in Firefox core. Objections?

Comment 34

[bugzilla.mozilla.org]

Now testing with Firefox 38.0a1 (2015-02-16) but the problem is still there.
I'm a bit further. I have enabled Nginx debug logging and there is a diffents in logging (when it fails or works).
When login fails Nginx debug logging shows:
2015/02/16 22:52:22 [info] 3691#0: *1 client sent WINDOW_UPDATE frame for unknown stream 273 while processing SPDY, client: 10.10.0.1, server: 0.0.0.0:443

I't shows this logging mutiple times and only the 273 changes.
I will report in Core/Networking and point to this report.

Comment 35

[bugzilla.mozilla.org]

Posted in Core/Networking:
https://bugzilla.mozilla.org/show_bug.cgi?id=1133598

Comment 36

[[:MakeMyDay]]

No objections. This looks like a problem of serverside SPDY implementation/configuration to me. There have been WFM comments above, so resolving this bug that way again.