Error: too many open files

gchen · 9 February 2020 15:09

I read your first post again and realized that it was just a warning, not a failure. That chunk couldn’t be saved in the local cache and the only side effect was that it would be downloaded again in case it is needed later.

In addition, it looks like a samba mount so it must be samba that opened too many files at a time when there were many chunks to be saved to the local cache. You’re less likely to see this warning again after most chunks are already in the local cache.

But, the temporary directory (repositories) should not be on a samba mount to begin with, because the cache is supposed to be local.

Christoph · 10 February 2020 20:40

I don’t know linux so well, but I don’t think this is a samba mount. What makes you think that?

Here is how my server is configured:

Ubuntu is running on a small SSD and
the main storage (a ZFS pool) is mounted as /srv/NAS/ (the NAS directory is really not needed, it could just as well be directly in /srv but I wasn’t sure whether /srv is used for anything else so I added another level, just to be sure).
/srv/NAS/ contains a number of directories such as /srv/NAS/christoph that are also made available SMB shares, but /srv/NAS/duplicacy/ is not. (And even if it were, would it really matter since from the perspective of duplicacy, it is still a local directory and I wouldn’t know how it would know about it also being a samba share, no?) The reason why it is there is because that’s where basically all my free disk space is.

So is any of this a problem for duplicacy?

gchen · 11 February 2020 17:56

Sorry I thought it was a samba or NFS drive from the name. So it is the CLI that opened too many files. I don’t know why it would open more than 1024 files. Increasing the ulimit should definitely help but because it is a harmless warning I would hold off unless it happens again.

Christoph · 14 February 2020 07:33

It didn’t take so long until it happened again. Not exactly the same, but “too manu open files” is part of it:

2020-02-14 02:40:33.867 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot PC_C
2020-02-14 02:40:35.002 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/1' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/1: dial tcp: lookup webdav.pcloud.com on 127.0.0.53:53: dial udp 127.0.0.53:53: socket: too many open files)
2020-02-14 02:40:35.930 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/1' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/1: dial tcp: lookup webdav.pcloud.com on 127.0.0.53:53: dial udp 127.0.0.53:53: socket: too many open files)
2020-02-14 02:40:37.330 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/1' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/1: dial tcp: lookup webdav.pcloud.com on 127.0.0.53:53: dial udp 127.0.0.53:53: socket: too many open files)
2020-02-14 02:40:40.022 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/1' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/1: dial tcp: lookup webdav.pcloud.com on 127.0.0.53:53: dial udp 127.0.0.53:53: socket: too many open files)
2020-02-14 02:40:47.109 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/1' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/1: dial tcp: lookup webdav.pcloud.com on 127.0.0.53:53: dial udp 127.0.0.53:53: socket: too many open files)
2020-02-14 02:40:57.148 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/1' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/1: dial tcp: lookup webdav.pcloud.com on 127.0.0.53:53: dial udp 127.0.0.53:53: socket: too many open files)
2020-02-14 02:41:23.622 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/1' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/1: dial tcp: lookup webdav.pcloud.com on 127.0.0.53:53: dial udp 127.0.0.53:53: socket: too many open files)
2020-02-14 02:42:27.121 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/1' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/1: dial tcp: lookup webdav.pcloud.com on 127.0.0.53:53: dial udp 127.0.0.53:53: socket: too many open files)
2020-02-14 02:44:11.152 ERROR SNAPSHOT_INFO Failed to get the information on the snapshot PC_C at revision 1: Maximum backoff reached
Failed to get the information on the snapshot PC_C at revision 1: Maximum backoff reached

This is a strange combination of another error I have been seeing and the one reported in the OP.

Adding to all the strangeness in the other error (that the DNS lookup suddenly fails after the remote host has been contacted only minutes earlier), this one is even stranger the problem with the lookup suddenly is too many open files instead of no such host.

@gchen, could you explain how duplicacy constructs these error messages? I’m guessing that it is somehow passing on error messages that it gets from somewhere else?

gchen · 17 February 2020 05:50

This explained why the CLI opened so many files – each udp socket is a file descriptor too, and the Go resolver used too many sockets since the DNS resolver was down. So if you can figure out why the DNS resolver was down you won’t see this “too may files” error.

Christoph · 17 February 2020 08:18

I love it when completely weird situations (see also this topic) suddenly start to make sense

Could this be the solution:

Christoph · 20 July 2020 11:46

Unfortunately, this “too many open files” error keeps plaguing me even though I have set up a new server with a different operating system (Debian/ OpenMediaVault):

2020-07-20 04:23:08.749 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot NAS
2020-07-20 04:29:39.534 WARN DOWNLOAD_FILE_CACHE Failed to add the file snapshots/NAS/349 to the snapshot cache: open /.duplicacy-web/repositories/localhost/all/.duplicacy/cache/pcloud/snapshots/NAS/349.iorybnta.tmp: too many open files
2020-07-20 04:29:39.678 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/350' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/350: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-20 04:29:40.232 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/350' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/350: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-20 04:29:41.243 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/350' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/350: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-20 04:29:43.476 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/350' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/350: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-20 04:29:50.732 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/350' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/350: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-20 04:30:03.246 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/350' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/350: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-20 04:30:35.225 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/350' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/350: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-20 04:31:16.510 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/350' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/350: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-20 04:33:11.195 ERROR SNAPSHOT_INFO Failed to get the information on the snapshot NAS at revision 350: Maximum backoff reached
Failed to get the information on the snapshot NAS at revision 350: Maximum backoff reached

So I’m not sure anymore about that bug that I mentioned above. It is being discussed by the ubuntu people and although ubuntu is derived from Debian, I’m not sure I can assume that the same problem exists on my Debian server. And if it does, I’m not sure if I can just disable systemd-resolved as suggested here.

Any suggestions how I can finally get duplicacy web to work on my server?

gchen · 23 July 2020 03:52

2020-07-20 04:29:39.534 WARN DOWNLOAD_FILE_CACHE Failed to add the file snapshots/NAS/349 to the snapshot cache: open /.duplicacy-web/repositories/localhost/all/.duplicacy/cache/pcloud/snapshots/NAS/349.iorybnta.tmp: too many open files

This means it already ran out of file descriptors before the DNS resolver was trying to resolve webdav.pcloud.com. So it was not the DNS resolver’s fault – it just didn’t have a free file descriptor to open a socket.

What if you move the temporary directory from /.duplicacy-web/repositories/ to something under /tmp, like /tmp/duplicacy/repositories?

Christoph · 25 July 2020 00:31

Indeed, after changing to /tmp/, I seem to be no longer getting “too many open files”. How can changing the path have this effect?

But the job nevertheless fails. Now like this:

2020-07-25 01:57:23.583 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot SERVER
2020-07-25 02:01:31.686 INFO WEBDAV_RETRY URL request 'MKCOL snapshots/SERVER' returned status code 401
2020-07-25 02:01:33.314 INFO WEBDAV_RETRY URL request 'PROPFIND snapshots/SERVER/204' returned status code 401
2020-07-25 02:02:12.717 INFO WEBDAV_RETRY URL request 'MKCOL snapshots/SERVER' returned status code 401
2020-07-25 02:02:14.662 INFO WEBDAV_RETRY URL request 'GET snapshots/SERVER/238' returned status code 401
2020-07-25 02:02:59.632 INFO WEBDAV_RETRY URL request 'MKCOL snapshots/SERVER' returned status code 401
2020-07-25 02:09:01.534 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot ALPHA_C
2020-07-25 02:15:02.943 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot NAS
2020-07-25 02:18:22.649 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/159' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/159: dial tcp: lookup webdav.pcloud.com on 208.67.222.2:53: no such host)
2020-07-25 02:18:23.196 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/159' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/159: dial tcp: lookup webdav.pcloud.com on 208.67.222.2:53: no such host)
2020-07-25 02:18:24.260 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/159' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/159: dial tcp: lookup webdav.pcloud.com on 208.67.222.2:53: no such host)
2020-07-25 02:18:27.188 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/159' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/159: dial tcp: lookup webdav.pcloud.com on 208.67.222.2:53: no such host)
2020-07-25 02:18:31.328 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/159' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/159: dial tcp: lookup webdav.pcloud.com on 208.67.222.2:53: no such host)
2020-07-25 02:18:43.355 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/159' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/159: dial tcp: lookup webdav.pcloud.com on 208.67.222.2:53: no such host)
2020-07-25 02:19:08.521 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/159' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/159: dial tcp: lookup webdav.pcloud.com on 208.67.222.2:53: no such host)
2020-07-25 02:19:47.403 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/159' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/159: dial tcp: lookup webdav.pcloud.com on 208.67.222.2:53: no such host)
2020-07-25 02:21:10.069 ERROR SNAPSHOT_INFO Failed to get the information on the snapshot NAS at revision 159: Maximum backoff reached
Failed to get the information on the snapshot NAS at revision 159: Maximum backoff reached

What does this mean?

gchen · 26 July 2020 16:25

Your DNS resolver running on 208.67.222.2:53 is down.

Christoph · 26 July 2020 17:15

Not sure what’s going on there. 208.67.222.2 is from OpenDNS and it is my secondary DNS, the primary one being 1.1.1.1 (cloudflare). No idea why it’s not using cloudflare. But I guess, I should get rid of the openDNS server.

Edit:
Plus, what I understand even less: why does duplicacy need to look up webdav.pcloud.com mid way through the process, after it has been downloading data from that same url for an hour or so? Doesn’t it remember the IP?

saspus · 26 July 2020 20:29

By default some (most?) resolvers use all configured upsteam resolvers. If you use dnsmasq see the option --all-servers. You can configure it to use secondary resolvers only if the primary is down: see --strict-order for dnsmasq.

And on a tangential – if you use OpenDNS for family/malware filtering Cloudflare now also have family/malware filtered resolvers – 1.0.0. and 1.1.1. ending .2 and .3

Christoph · 26 July 2020 21:21

As I’m thinking about it, my new setup is actually a bit more complex. I’m using pihole on a local machine as my primary DNS and OpenDNS as secondary (for no particular reason). Pihole then is set up to use one or more of cloudflare’s DNS.

So I didn’t actually expect the secondary DNS to be used at all because the first one is backed by multiple others. So thanks for explaining that secondary doesn’t really mean secondary. I now realise that my redundancy setup is wrong and I need to get rid of the secondary DNS (especially when it’s failing me anyway).

But let me try and get this back on topic: I’m still surprised that a single failing DNS server can make duplicacy fail. Why is that?

Christoph · 29 July 2020 22:10

Okay, now that duplicacy is using a functioning DNS server again, we’re back to the too many open files error again:

2020-07-29 03](nxphone:2020-07-29 03):42:47.379 INFO WEBDAV_RETRY URL request 'GET snapshots/NAS/400' returned status code 401
2020-07-29 03:43:00.227 INFO WEBDAV_RETRY URL request 'MKCOL snapshots/NAS' returned status code 401
2020-07-29 03:43:28.826 INFO WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/436' returned status code 401
2020-07-29 03:43:53.806 INFO WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/457' returned status code 401
2020-07-29 03:43:55.789 INFO WEBDAV_RETRY URL request 'MKCOL snapshots/NAS' returned status code 401
2020-07-29 03:45:05.202 INFO WEBDAV_RETRY URL request 'MKCOL snapshots/NAS' returned status code 401
2020-07-29 03:48:37.413 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot PC_C
2020-07-29 03:49:18.437 WARN DOWNLOAD_FILE_CACHE Failed to add the file snapshots/PC_C/281 to the snapshot cache: open /tmp/.duplicacy-web/repositories/localhost/all/.duplicacy/cache/pcloud/snapshots/PC_C/281.mmmxwsca.tmp: too many open files
2020-07-29 03:49:18.578 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/284' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/284: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-29 03:49:19.508 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/284' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/284: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-29 03:49:20.656 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/284' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/284: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-29 03:49:23.746 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/284' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/284: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-29 03:49:30.407 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/284' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/284: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-29 03:49:43.434 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/284' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/284: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-29 03:50:05.770 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/284' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/284: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-29 03:50:51.012 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/284' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/284: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-07-29 03:52:36.784 ERROR SNAPSHOT_INFO Failed to get the information on the snapshot PC_C at revision 284: Maximum backoff reached
Failed to get the information on the snapshot PC_C at revision 284: Maximum backoff reached

There also seems to be an authentication issue which is probably pCloud’s fault (their webdav interface intermittently claims that I don’t have access to some of my files or directories but that usually goes away again) but it doesn’t seem to cause the job to fail.

Christoph · 3 August 2020 20:57

@gchen Errors just keep piling up. In addition to the usual “too many open files” error that eventually kills the whole job, there are now even EOF errors TLS handshake timeout errors, and connection reset by peer, I would assume that the latter are pclouds fault but the biggest problem is the too many open files error which, as far as I can see, has nothing to do with pcloud…

2020-08-03 14:55:54.584 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot SERVER
2020-08-03 15:00:36.427 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/SERVER/302' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/SERVER/302: EOF)
2020-08-03 15:01:01.940 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/SERVER/309' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/SERVER/309: EOF)
2020-08-03 15:02:00.243 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/SERVER/351' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/SERVER/351: EOF)
2020-08-03 15:02:28.192 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/SERVER/362' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/SERVER/362: EOF)
2020-08-03 15:03:36.858 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/SERVER/418' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/SERVER/418: EOF)
2020-08-03 15:05:17.215 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/SERVER' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/SERVER: EOF)
2020-08-03 15:05:33.472 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/SERVER' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/SERVER: EOF)
2020-08-03 15:07:06.861 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/SERVER/558' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/SERVER/558: net/http: TLS handshake timeout)
2020-08-03 15:07:09.039 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot SURFACE
2020-08-03 15:07:11.180 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot ext_MEETGOV
2020-08-03 15:07:13.436 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot NAS_media
2020-08-03 15:07:14.661 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot PC_C
2020-08-03 15:10:51.497 TRACE WEBDAV_RETRY URL request 'GET snapshots/PC_C/368' returned an error (Get https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/368: EOF)
2020-08-03 15:12:40.752 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/399' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/399: EOF)
2020-08-03 15:13:32.064 TRACE WEBDAV_RETRY URL request 'GET snapshots/PC_C/402' returned an error (Get https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/402: EOF)
2020-08-03 15:13:55.211 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: read tcp 192.168.1.4:57474->74.120.8.227:443: read: connection reset by peer)
2020-08-03 15:15:29.698 TRACE WEBDAV_RETRY URL request 'GET snapshots/PC_C/415' returned an error (Get https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/415: EOF)
2020-08-03 15:16:46.433 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: EOF)
2020-08-03 15:17:32.275 TRACE WEBDAV_RETRY URL request 'GET snapshots/PC_C/448' returned an error (Get https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/448: net/http: TLS handshake timeout)
2020-08-03 15:21:04.631 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/510' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/510: EOF)
2020-08-03 15:21:17.415 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: EOF)
2020-08-03 15:21:51.264 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/519' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/519: EOF)
2020-08-03 15:22:28.778 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/523' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/523: EOF)
2020-08-03 15:22:59.490 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/525' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/525: EOF)
2020-08-03 15:23:24.157 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: EOF)
2020-08-03 15:23:52.493 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: EOF)
2020-08-03 15:24:03.587 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: net/http: TLS handshake timeout)
2020-08-03 15:24:15.640 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: net/http: TLS handshake timeout)
2020-08-03 15:24:28.674 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: net/http: TLS handshake timeout)
2020-08-03 15:25:01.676 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/PC_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C: read tcp 192.168.1.4:58080->74.120.8.227:443: read: connection reset by peer)
2020-08-03 15:26:20.427 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/557' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/557: EOF)
2020-08-03 15:26:57.442 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/559' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/559: EOF)
2020-08-03 15:27:44.235 TRACE WEBDAV_RETRY URL request 'GET snapshots/PC_C/559' returned an error (Get https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/559: EOF)
2020-08-03 15:28:37.823 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/579' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/579: net/http: TLS handshake timeout)
2020-08-03 15:30:54.426 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/636' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/636: EOF)
2020-08-03 15:32:28.371 TRACE WEBDAV_RETRY URL request 'GET snapshots/PC_C/658' returned an error (Get https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/658: EOF)
2020-08-03 15:33:04.132 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/PC_C/661' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/PC_C/661: EOF)
2020-08-03 15:33:46.328 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot PC_deleted
2020-08-03 15:33:47.877 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot ALPHA_D_COP
2020-08-03 15:33:58.043 TRACE SNAPSHOT_LIST_REVISIONS Listing revisions for snapshot NAS
2020-08-03 15:34:37.866 WARN DOWNLOAD_FILE_CACHE Failed to add the file snapshots/NAS/24 to the snapshot cache: open /tmp/.duplicacy-web/repositories/localhost/all/.duplicacy/cache/pcloud/snapshots/NAS/24.qhciziks.tmp: too many open files
2020-08-03 15:34:38.031 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/25' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/25: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-08-03 15:34:38.608 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/25' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/25: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-08-03 15:34:40.152 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/25' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/25: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-08-03 15:34:43.237 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/25' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/25: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-08-03 15:34:47.653 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/25' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/25: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-08-03 15:34:57.343 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/25' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/25: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-08-03 15:35:14.259 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/25' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/25: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-08-03 15:35:46.833 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/NAS/25' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/NAS/25: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-08-03 15:36:56.577 ERROR SNAPSHOT_INFO Failed to get the information on the snapshot NAS at revision 25: Maximum backoff reached
Failed to get the information on the snapshot NAS at revision 25: Maximum backoff reached

Christoph · 3 September 2020 19:49

@gchen I’m still stuck with this issue. Not a single check command has been completed because of this. Allthough I am inclined to believe that pCloud’s webdav interface is not exactly making things better, It seems clear that the too many open files problem is a local problem so that even if pCloud is creating some errors, duplicacy is also somehow failing in handling these.

It also seems likely that this is a duplicacy problem, because I have been seeing this very same problem on two different machines, one Ubuntu 18.04 server and now on a freshly installed Debian 10 machine (OpenMediaVault). I have not modified the Debian OS (all my apps are running in various docker containers) so I don’t see how this is not a duplicacy bug or design fault…

2020-09-02 23:34:58.996 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/252' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/252: EOF)
2020-09-02 23:35:23.063 TRACE WEBDAV_RETRY URL request 'MKCOL snapshots/ALPHA_C' returned an error (Mkcol https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C: EOF)
2020-09-02 23:35:49.455 WARN DOWNLOAD_FILE_CACHE Failed to add the file snapshots/ALPHA_C/272 to the snapshot cache: open /tmp/.duplicacy-web/repositories/localhost/all/.duplicacy/cache/pcloud/snapshots/ALPHA_C/272.pcwrzhfe.tmp: too many open files
2020-09-02 23:35:49.612 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/273' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/273: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-09-02 23:35:50.483 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/273' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/273: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-09-02 23:35:52.041 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/273' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/273: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-09-02 23:35:55.082 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/273' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/273: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-09-02 23:36:00.451 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/273' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/273: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-09-02 23:36:09.710 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/273' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/273: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-09-02 23:36:27.985 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/273' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/273: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-09-02 23:37:09.796 TRACE WEBDAV_RETRY URL request 'PROPFIND snapshots/ALPHA_C/273' returned an error (Propfind https://webdav.pcloud.com/Backup/Duplicacy/snapshots/ALPHA_C/273: dial tcp: lookup webdav.pcloud.com on 1.1.1.1:53: dial udp 1.1.1.1:53: socket: too many open files)
2020-09-02 23:39:14.283 ERROR SNAPSHOT_INFO Failed to get the information on the snapshot ALPHA_C at revision 273: Maximum backoff reached
Failed to get the information on the snapshot ALPHA_C at revision 273: Maximum backoff reached

saspus · 3 September 2020 20:54

Not exactly helpful comment but this is exactly why Duplicacy should drop support for file sharing storage backends. They are not designed for bulk storage and will fail in weird in wonderful way — exemplified by this topic — and ultimately result is user frustration and extra futile support workload for Acrosync.

More organized thoughts on this here: (Newbie) Backup entire machine?

Christoph · 3 September 2020 23:41

I’m willing to admit that I wasted - I think it was 500 USD - when buying 4TB of lifetime storage from pCloud; I was not aware of the differences that you explain so well in the other post… But are you saying that only pCloud is to blame? I don’t understand the logs 100% but it seems clear to me that duplicacy is not handling whatever problems pCloud is having properly, no?

saspus · 3 September 2020 23:53

I did not watch the thread too carefully but 401(unauthorized) and TLS handshake timeout is fairly certainly either service issues or their anti-abuse measures. Either way not good for intended purpose.

Duplicacy should keep trying to back off and retry with increasing interval — and maybe it does fail to do so in some cases but it’s too late anyway. Service has already face planted.

The too many open files does look like client side issue — perhaps you are hitting limit on max open files? You can run lsof to see who has holding what handles and then act accordingly (murder the offending process or report Duplicacy bug or increase handles limit). Maybe indeed there is a bug handling failed connections and Duplicacy is not letting go the orphaned connections?

gchen · 4 September 2020 01:16

What is the TTL of webdav.pcloud.com on your machine? On mine it is 7200 seconds. If this TTL is too small there will be too many DNS requests.

$ dig +nocmd +noall +answer webdav.pcloud.com
webdav.pcloud.com.	7199	IN	A	74.120.8.227

I think you should keep running lsof once Duplicacy starts. Maybe write a script to save the output of lsof to a file every minute. You should be watching all file descriptors opened by the Duplicacy CLI, not the web GUI. If the list of file descriptors keeps grow, it may be fairly obvious what is leaking.