It hangs indefinetly too. If it matters the used disk space of the server is 60004KB and the hard limit is 60005KB. I started the backup when the used disk space was 60000KB. As we speak it is hanging with the message Waiting for upload to finish ….
@Kanellaman
There is a discrepancy between what we see that begs for an explanation.
Couldn’t write to remote file “/fichiers/myfile.txt”: Failure
It’s coherent with what I see in Duplicati (after all it’s the same server)
Err, you are using a recent Duplicati version ?
I am using the latest Duplicati version.
probably not since your C# client hangs - if you are using Windows, how about downloading psftp (the software coming with putty) to test it ?
I used psftp as you suggested and indeed I get the errorerror while writing: failure
ts678
January 10, 2024, 1:31pm
26
I’d worry about filling a filesystem the OS was relying on, but maybe you used tmpfs or a loop mount?
OpenSSH Specifications at least says what they support – draft-ietf-secsh-filexfer-02 – an earlier one.
SSH File Transfer Protocol
Add SSH_FX_NO_SPACE_ON_FILESYSTEM, SSH_FX_QUOTA_EXCEEDED, and
I suppose you can see if the OpenSSH Manual Pages logging offerings can get you that information.
-v
in sftp might be the easiest to try out, but sftp-server seems to provide an extensive set of log options.
psftp might accept -v: increase verbosity, but I didn’t immediately find the exact documentation.
Short error messages so far seem to match the error code well, but any hang chase might need more.
I setup data servers (ftp, sftp) on separate partitions.
A bit sad - to be fair, portability may be a problem.
It may come from the quota thing. I have never tried that. I use a much simpler way of limiting data on my sftp/ftp servers: a separate partition. But of course I don’t worry about several users.
Well using man sftp-server I saw this T. Ylonen and S. Lehtinen, SSH File Transfer Protocol, draft-ietf-secsh-filexfer-02.txt, October 2001, work in progress material.draft-ietf-secsh-filexfer-05.txt and see if it fixes things.
I don’t think such a thing exists. I downloaded git openssh and checked that.
ts678
January 10, 2024, 2:16pm
31
??? I’m quoting today’s OpenSSH documentation. Maybe you mean you’ll try another brand of server? There are plenty of FTP server options, but I don’t know follow SSH/SFTP servers nearly so closely…
It depends on the goal. If you want a more accurate error, that’s one thing. Hang avoidance is another.
I’m not sure the developer you’re working with was able to get a hang repro, and I don’t know why, but possibly you could use the logging options I mentioned to try to understand what the program is doing.
@Kanellaman
All right, I can repro it with Proftpd with quotas on. On Mono or on Windows, do not matter.SSH.NET problem
I’ll let @ts678 provide links to the SSH.NET issues here and it begs for some investigation for sure. It’s supposed to throw exceptions when bad things happen and it don’t seem to do that.
A workaround is to set ssh-operation-timeout - I set it to 5 minutes and it allows at least to terminate the job (ungracefully of course).
ts678
January 10, 2024, 6:47pm
34
It’s the top link on Google for ssh.net issues. Then you look around for things like quota and space.
SftpClient.UploadFile hangs indefinitely when server has run out of space #343 is referenced from:
opened 10:24AM - 02 Feb 22 UTC
- [x] I have searched open and closed issues for duplicates.
- [x] I have searc… hed the [forum](https://forum.duplicati.com) for related topics.
----------------------------------------
## Issue
When Remote SSH runs out of disk-space, Duplicati fails by
1) either hanging
2) or giving an unknown error in the GUI with no clear cause, and nothing is written in the local-db logs (click logs in gui-error) but with something written in the external log-file (information level).
These two separate behaviors should probably be interpreted at two separate bugs (or more precisely: I'm pretty sure they require two separate code-changes).
## Environment info
- **Duplicati version**: 2.0.6.3_beta_2021-06-17
- **Operating system**: Linux, docker, linuxserver/duplicati
- **Backend**: SSH, Linux
## Steps to reproduce
Note I experience two different behaviors for the same underlying issue. Either it'll give me a GUI error as shown in the screenshot further down, or it will just hang in processing as ssh upload fails. Note that the GUI error happened on all my jobs that had previously succeeded (ie. first and following times backend ran full), and the hang-issue came after I recreated the local database (I didn't know it was an out-of-space error at that time).
1. Fill Remote
2. run backup with a (1GB?) file to put
3. Duplicati gets stuck in Processing in GUI on that file, while logs show as last line `Backend event: Put - Started: `. Also `lsof` indicates mono process still has open handles to the file being backed up. And the remote linux log says `No space left on device`
```
2022-02-02 10:00:02 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b54b54a6639f34f1281c35eeb81fb2838.dblock.zip.aes (147.03 MB)
```
## Screenshots
<img width="588" alt="Duplicati-bug" src="https://user-images.githubusercontent.com/2171240/152134498-054e7ccc-e272-4410-88cc-2fc3d2a3e874.PNG">
<img width="389" alt="Duplicati-bug2" src="https://user-images.githubusercontent.com/2171240/152163879-90244492-4956-49c2-86fd-74e7a194f688.PNG">
Remote linux OS log (the log from the remote system we are uploading the backup to):
`Feb 2 01:00:10 UnRaidBackup sftp-server[27869]: error: process_write: write: No space left on device`
## Debug log
Information level log from backup. Note that its the last few lines that are from this backup. The first lines probably indicate cleanup due to previous backups put-problems. It'll hang all night from my experience (forever?).
```
2022-02-02 09:56:01 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started
2022-02-02 09:56:03 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()
2022-02-02 09:56:15 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (57.16 KB)
2022-02-02 09:56:18 +01 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-KeepIncompleteFile]: keeping protected incomplete remote file listed as Temporary: duplicati-20220201T220121Z.dlist.zip.aes
2022-02-02 09:56:18 +01 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-b36bf4e6d45bf4c54a283913a4ced8674.dblock.zip.aes
2022-02-02 09:56:18 +01 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-Remove incomplete file]: removing incomplete remote file listed as Uploading: duplicati-bf91c0e827e6b4bf3835078dbac423491.dblock.zip.aes
2022-02-02 09:56:18 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-bf91c0e827e6b4bf3835078dbac423491.dblock.zip.aes (147.04 MB)
2022-02-02 09:56:18 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-bf91c0e827e6b4bf3835078dbac423491.dblock.zip.aes (147.04 MB)
2022-02-02 09:56:20 +01 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-PromotingCompleteFile]: promoting uploaded complete file from Uploading to Uploaded: duplicati-ba5e43643fa744104b2120ffbb9716dcd.dblock.zip.aes
2022-02-02 09:56:20 +01 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-b6b38df471ac746e4bb386947590ed669.dblock.zip.aes
2022-02-02 09:56:20 +01 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-b994ec2902e8a42be9da555f1f84771af.dblock.zip.aes
2022-02-02 09:56:20 +01 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-b23b8c12352da4765926c74d23ac60ec5.dblock.zip.aes
2022-02-02 09:56:20 +01 - [Information-Duplicati.Library.Main.Operation.Backup.UploadSyntheticFilelist-PreviousBackupFilelistUpload]: Uploading filelist from previous interrupted backup
2022-02-02 09:56:22 +01 - [Information-Duplicati.Library.Main.Operation.Backup.RecreateMissingIndexFiles-RecreateMissingIndexFile]: Re-creating missing index file for duplicati-ba5e43643fa744104b2120ffbb9716dcd.dblock.zip.aes
2022-02-02 09:56:22 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-ief0607c9e2734cc28e96869940d95156.dindex.zip.aes (1.64 KB)
2022-02-02 09:56:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-ief0607c9e2734cc28e96869940d95156.dindex.zip.aes (1.64 KB)
2022-02-02 10:00:02 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b54b54a6639f34f1281c35eeb81fb2838.dblock.zip.aes (147.03 MB)
```
Local logs when GUI shows error (but link to logs is empty)
```
Renci.SshNet.Common.SshException: Failure
at Renci.SshNet.Sftp.SftpSession.RequestOpen (System.String path, Renci.SshNet.Sftp.Flags flags, System.Boolean nullOnError) [0x0008c] in <8c66a76a693c4e52b456ec0712c863dd>:0
at Renci.SshNet.SftpClient.InternalUploadFile (System.IO.Stream input, System.String path, Renci.SshNet.Sftp.Flags flags, Renci.SshNet.Sftp.SftpUploadAsyncResult asyncResult, System.Action`1[T] uploadCallback) [0x0004f] in <8c66a76a693c4e52b456ec0712c863dd>:0
at Renci.SshNet.SftpClient.UploadFile (System.IO.Stream input, System.String path, System.Boolean canOverride, System.Action`1[T] uploadCallback) [0x00017] in <8c66a76a693c4e52b456ec0712c863dd>:0
at Renci.SshNet.SftpClient.UploadFile (System.IO.Stream input, System.String path, System.Action`1[T] uploadCallback) [0x00000] in <8c66a76a693c4e52b456ec0712c863dd>:0
at Duplicati.Library.Backend.SSHv2.PutAsync (System.String remotename, System.IO.Stream stream, System.Threading.CancellationToken cancelToken) [0x00012] in <a59f77bd59444f6a92f1348e2a58cec6>:0
at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoPut (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Interface.IBackend backend, System.Threading.CancellationToken cancelToken) [0x003a4] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at Duplicati.Library.Main.Operation.Backup.BackendUploader+<>c__DisplayClass20_0.<UploadFileAsync>b__0 () [0x0010a] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x0017c] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x003a5] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadFileAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000da] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadBlockAndIndexAsync (Duplicati.Library.Main.Operation.Backup.VolumeUploadRequest upload, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x00098] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at Duplicati.Library.Main.Operation.Backup.BackendUploader.<Run>b__13_0 (<>f__AnonymousType12`1[<Input>j__TPar] self) [0x00780] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at Duplicati.Library.Main.Operation.Backup.BackendUploader.<Run>b__13_0 (<>f__AnonymousType12`1[<Input>j__TPar] self) [0x007d7] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at CoCoL.AutomationExtensions.RunTask[T] (T channels, System.Func`2[T,TResult] method, System.Boolean catchRetiredExceptions) [0x000d5] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0
at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend (Duplicati.Library.Main.BackupResults result, CoCoL.IWriteChannel`1[T] uploadtarget, System.Threading.Tasks.Task uploader) [0x000f2] in <e60bc008dd1b454d861cfacbdd3760b9>:0
at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00cb2] in <e60bc008dd1b454d861cfacbdd3760b9>:0
```
## Possibly related issues
Note that none of these issues indicate remote disk full as the underlying cause of the issue.
https://github.com/duplicati/duplicati/issues/2968
https://github.com/duplicati/duplicati/issues/2351
## Thoughts...
Idea: If possible it would be valuable to add remote free-space to information level log on backup start+stop. That would make debugging disk space issues easier.
UploadFile is used at
public Task PutAsync(string remotename, System.IO.Stream stream, CancellationToken cancelToken)
{
CreateConnection();
ChangeDirectory(m_path);
m_con.UploadFile(stream, remotename);
return Task.FromResult(true);
}
Is there something we could put in their open issue (maybe a repro) to see if it will lead to faster fix?
ts678
January 10, 2024, 6:51pm
35
I’m not sure if I saw that in this topic, but a simple repro might assist the SSH.NET issue.
ts678:
a simple repro
Yes that would be a good thing but using SSH.NET . I (vaguely) intend to do that. Truth to be said, I expect to have to debug the thing myself.
ts678
January 10, 2024, 7:06pm
37
I didn’t know it didn’t. I now wonder what the code did.
If making a simple SSH.NET C# repro isn’t desired, Duplicati.CommandLine.BackendTool.exe might do.
I am kinda lost here guys SSH.NET afterall? How so? The error code returned (4) isn’t handled well? Or it is something else?
Would that impact slow connectivity issues? If a file takes more than 5 minutes duo to slow internet will the connection be dropped?
EDITssh.net library not handling it well)?
ts678
January 11, 2024, 12:16pm
39
Kanellaman:
Or it is something else?
I would guess the “have to debug the thing myself” refers to SSH.NET , but it’s still way early in that.
There are 2 distinct problems.
when the problem is caused by a full partition, SSH.NET (hence Duplicati) is handling the failure reasonably well, except that the error code is wrong, and ssh (the server) is at fault
when the problem is caused by a quota, I have found a hang, like you said. It is more likely that SSH.NET is at fault, but as I don’t know why this hang occurs, I can’t be sure.
The maximum file size with Duplicati is around 50 MB. If you have fiber (about 8 Mbits/s upload at least, usually more), such a file should transmit in about 1 minute so a 5 minutes delay is more than enough. If you have ADSL (about 1 Mbits/s) the timeout should be set to 10 minutes at least.
it looks like it. As I said, I don’t know what is causing the hang with quota. If the software handling the quota don’t fail when the quota is exceeded but just, well, keep the current write operation waiting
@ts678
1 Like
but you can find them yourself. The code is here and it begs for some investigation for sure. It’s supposed to throw exceptions when bad things happen and it don’t seem to do that.