WebDAV "SSLError: The read operation timed out" on goneo.de

Asked by A.M.

Hi
I'm trying to back my stuff up to my goneo.de clound (german site) with WebDAV from my FreeNAS. I get the SSLError at 5 attempts and then it aborts. This is the debug log:

Using archive dir: /root/.cache/duplicity/fd782457b1febd1d5dc2bce83bb8720a
Using backup name: fd782457b1febd1d5dc2bce83bb8720a
Import of duplicity.backends.ftpbackend Succeeded
Import of duplicity.backends.megabackend Succeeded
Import of duplicity.backends.hsibackend Succeeded
Import of duplicity.backends.ftpsbackend Succeeded
Import of duplicity.backends.tahoebackend Succeeded
Import of duplicity.backends.dpbxbackend Succeeded
Import of duplicity.backends.localbackend Succeeded
Import of duplicity.backends.sshbackend Succeeded
Import of duplicity.backends.imapbackend Succeeded
Import of duplicity.backends.rsyncbackend Succeeded
Import of duplicity.backends.swiftbackend Succeeded
Import of duplicity.backends.botobackend Succeeded
Import of duplicity.backends.webdavbackend Succeeded
Using WebDAV protocol http
Using WebDAV host cloud1.goneo.de port None
Using WebDAV directory /share/
Main action: full
================================================================================
duplicity 0.6.23 (January 24, 2014)
Args: /usr/local/bin/duplicity full --ssl-no-check-certificate -v9 /media/Pictures/Random/ webdavs://user:<email address hidden>/share/
FreeBSD duplicity 9.2-RELEASE-p4 FreeBSD 9.2-RELEASE-p4 #0 r262572+36f49d3: Fri Apr 18 04:16:22 PDT 2014 <email address hidden>:/home/jkh/9.2.1-BRANCH/freenas/os-base/amd64/tank/home/jkh/9.2.1-BRANCH/freenas/FreeBSD/src/sys/FREENAS.amd64 amd64 amd64
/usr/local/bin/python2.7 2.7.6 (default, Feb 6 2014, 13:32:45)
[GCC 4.2.1 20070831 patched [FreeBSD]]
================================================================================
Using temporary directory /tmp/duplicity-Q8YryV-tempdir
Registering (mkstemp) temporary file /tmp/duplicity-Q8YryV-tempdir/mkstemp-DMKGHr-1
Temp has 765166151680 available, backup will use approx 34078720.
Listing directory /share/ on WebDAV server
WebDAV create connection on 'cloud1.goneo.de' (retry 1)
WebDAV PROPFIND /share/ request with headers: {'Connection': 'keep-alive', 'Depth': '1'}
WebDAV data length: 0
WebDAV response status 401 with reason 'Unauthorized'.
WebDAV retry request with authentification headers.
WebDAV PROPFIND /share/ request2 with headers: {'Connection': 'keep-alive', 'Depth': '1', 'Authorization': 'Digest username="xxx", realm="ajxp_webdav_realm", nonce="5362cbd2e5f41", uri="/share/", response="4affe83e7f5aa0faae7b5c32a456d58a", opaque="df58bdff8cf60599c939187d0b5c54de", algorithm="MD5", qop=auth, nc=00000001, cnonce="5423e456536ee616"'}
WebDAV data length: 0
WebDAV response2 status 200 with reason ''.
Attempt 1 failed. SSLError: The read operation timed out
Backtrace of previous error: Traceback (innermost last):
  File "/usr/local/lib/python2.7/site-packages/duplicity/backend.py", line 344, in _retry_fatal
    return fn(self, *args)
  File "/usr/local/lib/python2.7/site-packages/duplicity/backends/webdavbackend.py", line 297, in _list
    raise e
 SSLError: The read operation timed out

The strange thing is that WebDAV works on my owncloud running on my NAS, but when I try this for goneo I keep getting this. Yes, I did try without --ssl-no-check-certificate and even with pointing to the cacert.pem file located at /etc/duplicity/.
The even stranger thing is that it works fine on folderSync on my phone when I setup a WebDAV account with the exact same information as above. I don't even have to hit the "accept self signed certs".
A friend of mine set this up on his VM and he gets the exact same error.
I hope that you can tell me what's going on here. As far as I can say the error is with duplicity and not with me/us/goneo. Any help is much appreciated!!

Question information

Language:
English Edit question
Status:
Solved
For:
Duplicity Edit question
Assignee:
No assignee Edit question
Solved by:
edso
Solved:
Last query:
Last reply:
Revision history for this message
edso (ed.so) said :
#1

On 02.05.2014 01:41, A.M. wrote:
> Question #248020 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/248020
>
> Description changed to:
> Hi
> I'm trying to back my stuff up to my goneo.de clound (german site) with WebDAV from my FreeNAS. I get the SSLError at 5 attempts and then it aborts. This is the debug log:
>
> Using archive dir: /root/.cache/duplicity/fd782457b1febd1d5dc2bce83bb8720a
> Using backup name: fd782457b1febd1d5dc2bce83bb8720a
> Import of duplicity.backends.ftpbackend Succeeded
> Import of duplicity.backends.megabackend Succeeded
> Import of duplicity.backends.hsibackend Succeeded
> Import of duplicity.backends.ftpsbackend Succeeded
> Import of duplicity.backends.tahoebackend Succeeded
> Import of duplicity.backends.dpbxbackend Succeeded
> Import of duplicity.backends.localbackend Succeeded
> Import of duplicity.backends.sshbackend Succeeded
> Import of duplicity.backends.imapbackend Succeeded
> Import of duplicity.backends.rsyncbackend Succeeded
> Import of duplicity.backends.swiftbackend Succeeded
> Import of duplicity.backends.botobackend Succeeded
> Import of duplicity.backends.webdavbackend Succeeded
> Using WebDAV protocol http
> Using WebDAV host cloud1.goneo.de port None
> Using WebDAV directory /share/
> Main action: full
> ================================================================================
> duplicity 0.6.23 (January 24, 2014)
> Args: /usr/local/bin/duplicity full --ssl-no-check-certificate -v9 /media/Pictures/Random/ webdavs://user:<email address hidden>/share/
> FreeBSD duplicity 9.2-RELEASE-p4 FreeBSD 9.2-RELEASE-p4 #0 r262572+36f49d3: Fri Apr 18 04:16:22 PDT 2014 <email address hidden>:/home/jkh/9.2.1-BRANCH/freenas/os-base/amd64/tank/home/jkh/9.2.1-BRANCH/freenas/FreeBSD/src/sys/FREENAS.amd64 amd64 amd64
> /usr/local/bin/python2.7 2.7.6 (default, Feb 6 2014, 13:32:45)
> [GCC 4.2.1 20070831 patched [FreeBSD]]
> ================================================================================
> Using temporary directory /tmp/duplicity-Q8YryV-tempdir
> Registering (mkstemp) temporary file /tmp/duplicity-Q8YryV-tempdir/mkstemp-DMKGHr-1
> Temp has 765166151680 available, backup will use approx 34078720.
> Listing directory /share/ on WebDAV server
> WebDAV create connection on 'cloud1.goneo.de' (retry 1)
> WebDAV PROPFIND /share/ request with headers: {'Connection': 'keep-alive', 'Depth': '1'}
> WebDAV data length: 0
> WebDAV response status 401 with reason 'Unauthorized'.
> WebDAV retry request with authentification headers.
> WebDAV PROPFIND /share/ request2 with headers: {'Connection': 'keep-alive', 'Depth': '1', 'Authorization': 'Digest username="xxx", realm="ajxp_webdav_realm", nonce="5362cbd2e5f41", uri="/share/", response="4affe83e7f5aa0faae7b5c32a456d58a", opaque="df58bdff8cf60599c939187d0b5c54de", algorithm="MD5", qop=auth, nc=00000001, cnonce="5423e456536ee616"'}
> WebDAV data length: 0
> WebDAV response2 status 200 with reason ''.
> Attempt 1 failed. SSLError: The read operation timed out
> Backtrace of previous error: Traceback (innermost last):
> File "/usr/local/lib/python2.7/site-packages/duplicity/backend.py", line 344, in _retry_fatal
> return fn(self, *args)
> File "/usr/local/lib/python2.7/site-packages/duplicity/backends/webdavbackend.py", line 297, in _list
> raise e
> SSLError: The read operation timed out
>
>
> The strange thing is that WebDAV works on my owncloud running on my NAS, but when I try this for goneo I keep getting this. Yes, I did try without --ssl-no-check-certificate and even with pointing to the cacert.pem file located at /etc/duplicity/.
> The even stranger thing is that it works fine on folderSync on my phone when I setup a WebDAV account with the exact same information as above. I don't even have to hit the "accept self signed certs".
> A friend of mine set this up on his VM and he gets the exact same error.
> I hope that you can tell me what's going on here. As far as I can say the error is with duplicity and not with me/us/goneo. Any help is much appreciated!!
>

there's currently no way to modify the default timeout values for https connections in the webdav backend. you might want to check python API docs and modify duplicity/backends/webdavbackend.py

alternatively you can give me temporary access to a goneo account and i can have a look at this. as i'm pretty busy this might take some weeks though.

..ede/duply.net

Revision history for this message
edso (ed.so) said :
#2
Revision history for this message
A.M. (a25) said :
#3

I don't think it has anything to do with the timeout seconds... "WebDAV response status 401 with reason 'Unauthorized'." suggests that something goes wrong on login, right?
I tried 120 seconds and it didn't work..

Revision history for this message
A.M. (a25) said :
#4

<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>Sabre\DAV\Exception\NotAuthenticated</s:exception>
  <s:message>No digest authentication headers were found</s:message>
  <s:sabredav-version>1.8.5</s:sabredav-version>
</d:error>

I think this is the main error! It tries to authenticate with "digest" (whatever that is), but it can't find any!

Revision history for this message
edso (ed.so) said :
#5

On 02.05.2014 18:36, A.M. wrote:
> Question #248020 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/248020
>
> A.M. posted a new comment:
> <?xml version="1.0" encoding="utf-8"?>
> <d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
> <s:exception>Sabre\DAV\Exception\NotAuthenticated</s:exception>
> <s:message>No digest authentication headers were found</s:message>
> <s:sabredav-version>1.8.5</s:sabredav-version>
> </d:error>
>
>
> I think this is the main error! It tries to authenticate with "digest"
> (whatever that is), but it can't find any!
>

hmm.. run duplicity with max. verbosity '-v9' and send the complete output to me privately for me to see what is going on. you might wanna change your credentials to the webdav afterwards, just to be sure.

..ede/duply.net

Revision history for this message
A.M. (a25) said :
#6

I did that above, but hang on, let me send you the new log.

Revision history for this message
A.M. (a25) said :
#7

So I think I know where the issue is.. This is what I get when I try to open the connection with duplicity. It's either that the username is transmitted incorrectly or not at all:

<?xml version="1.0" encoding="utf-8"?>
<d:error xmlns:d="DAV:" xmlns:s="http://sabredav.org/ns">
  <s:exception>Sabre\DAV\Exception\NotAuthenticated</s:exception>
  <s:message>No digest authentication headers were found</s:message>
  <s:sabredav-version>1.8.5</s:sabredav-version>
</d:error>

This is what I get in FireFox when I enter "https://cloud1.goneo.de/share", after a login prompt pops up and I simply press "cancel":

<d:error><s:exception>Sabre\DAV\Exception\NotAuthenticated</s:exception><s:message>No digest authentication headers were found</s:message><s:sabredav-version>1.8.5</s:sabredav-version></d:error>

So it's the exact same error. But before duplicity gives me the error mention aboved this is what happens:

WebDAV create connection on 'cloud1.goneo.de' (retry 1)
WebDAV PROPFIND /share/ request with headers: {'Connection': 'keep-alive', 'Depth': '1'}
WebDAV data length: 0
WebDAV response status 401 with reason 'Unauthorized'.
WebDAV retry request with authentification headers.
WebDAV PROPFIND /share/ request2 with headers: {'Connection': 'keep-alive', 'Depth': '1', 'Authorization': 'Digest username="username", realm="ajxp_webdav_realm", nonce="5364443b5d3c3", uri="/share/", response="e1b65f609d9327e6523ed081df6fb0d3", opaque="df58bdff8cf60599c939187d0b5c54de", algorithm="MD5", qop=auth, nc=00000001, cnonce="65ba0b24b406d99e"'}
WebDAV data length: 0
WebDAV response2 status 200 with reason ''.
124

My best quess is that it tries to login to cloud1.goneo.de/share, but because there's no username:pw it fails and then tries to login with the header (not quite sure what it is) and fails again because no data is entered (--> The same error I get on FireFox when entering nothing in the login prompt).

It's really important that you know that it works fine with FolderSync. I've set it to HTTPS, entered the URL (cloud.goneo.de), the start dir (share) and my credentials and it works like a charm..

Revision history for this message
edso (ed.so) said :
#8

Aria,

read up on HTTP auth methods if you are interested in how it works
http://en.wikipedia.org/wiki/Digest_access_authentication
http://en.wikipedia.org/wiki/Basic_access_authentication
you do not transfer passwords but hashes instead.

FolderSync is of no significance here as it simply signals the webdav service works at all. as webdav is merely a not very strictly defined http based protocol the implementation often differs in details. e.g. the server might expect some request text camelcased, but the client asks for lowercased, or the other way around.

the log you sent showed that the server
- didn't recognize the auth headers on the first try
- didn't like the username on the second to last tries

i suggest you start to investigate with the latter.

as long as i don't have access to a goneo account i can't try to reproduce your issue.

..ede/duply.net

Revision history for this message
A.M. (a25) said :
#9

So I looked at the console while logging in with a browser and it actually looks the same as on duplicity..

PC:

Connection: keep-alive
Authorization: Digest username="username", realm="ajxp_webdav_realm", nonce="some hash", uri="/share",
response="some hash", opaque="same hash as duplicity", qop=auth, nc=00000001, cnonce="some hash"

Duplicity:

WebDAV PROPFIND /share/ request2 with headers: {'Connection': 'keep-alive', 'Depth': '1', 'Authorization': 'Digest username="username",
realm="ajxp_webdav_realm", nonce="some hash", uri="/share/", response="some hash",
opaque="same hash as PC", algorithm="MD5", qop=auth, nc=00000001, cnonce="some hash"'}

Shouldn't that mean that all is good? :/

Revision history for this message
Best edso (ed.so) said :
#10

well .. that was fun, not really ;) it works. please contact me privately to tell me in which german city, should i ever travel through, you are going to buy me a beer :))

ok. the problem is three fold

first
 requests to https://cloud1.goneo.de/share/ take a very long time. that's why you got the timeout
 use /share/<userid> and it get's much quicker

secondly
 there's a bug in python httplib that leaks previous response data of a connection into the body of the next response even if the response was closed earlier
 that hits on first webdav connections - try to list, need auth, try list with auth, fail because of expat parsing error
 as your listing was never successful due to that, it retried numretries

thirdly
 you are not allowed properly access https://cloud1.goneo.de/share/
 i observed when i created a folder 'test' in /share with another webdav client, it vanished on the next login
 so i assumed together with the existence of the folder /share/<userid> that you might only be allowed to access that folder properly

tl;dr

use
 webdavs://cloud1.goneo.de/share/<userid>/duplicity-backup
and it should work. does for me.

ede/duply.net

PS: i couldn't figure out why the server sends wrong user/digest missing sometimes, but it probably goes together with the slow response time of /share access

Revision history for this message
A.M. (a25) said :
#11

I sure will give you your beer haha! Just let me know when you're north of Münster.

So it's true, /share takes really long, whereas share/userID is much much faster.

Just to confirm, I should use webdavs://username:<email address hidden>/share/userid/duplicity, right?

The full command is:

duplicity full -v9 --ssl-no-check-certificate --timeout=120 /source/dir/ webdavs://username:<email address hidden>/share/userid/duplicity

To be honest it still doesn't work for me! I created the folder Duplicity in share/userid (--> share/userid/Duplicity), but it still doesn't work and gives me the timeout -.- I even left out the password so that I could enter it on prompt, but still the same happens..

Revision history for this message
edso (ed.so) said :
#12

yeah, sorry right. the mentioned bug still needs to be fixed. find the following file of your local duplicity
 duplicity/backends/webdavbackend.py

edit around line 206

               elif response.status == 401:
insert --> response.read()
                     response.close()
                     self.headers['Authorization'] = self.get_authorization(response, quoted_path)

!!! make sure the indention is exactly the same as the lines below the inserted line.

..ede

Revision history for this message
A.M. (a25) said :
#13

I love you <3 Works like a charm!!!

Revision history for this message
A.M. (a25) said :
#14

Just one last question, can I make it show me the upload progress?

Revision history for this message
edso (ed.so) said :
#15

On 04.05.2014 18:31, A.M. wrote:
> Question #248020 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/248020
>
> A.M. posted a new comment:
> I love you <3 Works like a charm!!!
>

told you ;) .. have fun.. ede/duply.net

Revision history for this message
edso (ed.so) said :
#16

On 04.05.2014 18:46, A.M. wrote:
> Question #248020 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/248020
>
> A.M. posted a new comment:
> Just one last question, can I make it show me the upload progress?
>

no, there is a general progressbar though. look in the manpage
 http://duplicity.nongnu.org/duplicity.1.html

..ede

Revision history for this message
A.M. (a25) said :
#17

So the upload worked fine before but now the first 5 mins it says stalled:

0.0KB 00:00:09 [0.0B/s] [> ] 0% ETA Stalled!

And this comes every 3 seconds. Why's that? It wants to upload a 26MB file but now it won't :x

Revision history for this message
edso (ed.so) said :
#18

On 04.05.2014 19:11, A.M. wrote:
> Question #248020 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/248020
>
> A.M. posted a new comment:
> So the upload worked fine before but now the first 5 mins it says
> stalled:
>
> 0.0KB 00:00:09 [0.0B/s] [> ] 0%
> ETA Stalled!
>
> And this comes every 3 seconds. Why's that? It wants to upload a 26MB
> file but now it won't :x
>

some issue with the progress bar maybe.. try without it. ede

Revision history for this message
A.M. (a25) said :
#19

It is a problem with the progress bar actually, it did create those files :x

Revision history for this message
A.M. (a25) said :
#20

Thanks edso, that solved my question.

Revision history for this message
edso (ed.so) said :
#21

duplicity 0.6.24 contains the fix ..ede/duply.net