tbenz9 / siasync

miniscule utility to sync a folder with Sia
MIT License
67 stars 10 forks source link

"Unable to stat input file" error #18

Open buxm opened 4 years ago

buxm commented 4 years ago

Running siasync 1.0.1 Linux amd64 on a Synology NAS. Running siad in a docker container (https://github.com/mtlynch/docker-sia) on the same NAS

Running the following command: ./siasync -password xxxxxxxxxxxxxxx -subfolder BDSBackupTest -sync-only /volume1/Backup/TestSia1.hbk

I always obtain the following: 2019/11/20 23:29:14 Connected to Sia 1.4.1.2 2019/11/20 23:29:14 50 contracts are ready for upload 2019/11/20 23:30:45 Uploading files missing from Sia 2019/11/20 23:30:45 error uploading /volume1/Backup/TestSia1.hbk/Config/@cand_file/123_1.cand_dup: upload failed: [unable to stat input file; stat /volume1/Backup/TestSia1.hbk/Config/@cand_file/123_1.cand_dup: no such file or directory]

The name of the file after stat may change in each run, but the same error always happens.

After getting the above error, I immediately ran the following: stat /volume1/Backup/TestSia1.hbk/Config/@cand_file/123_1.cand_dup and I obtained the correct stat output for that file (no "no such file or directory" error)

I ran the same command with -debug debug.txt

and I can see that the error always occurs on the first file siasync tries to upload.

I also tried to run the same siasync command with sudo... but it didn't solve the issue (after all, when I run the stat command it works even without sudo).

Do you think this is a bug or am I doing something wrong? Many thanks.

tbenz9 commented 4 years ago

I don't think i've seen this before. Can you try with an older version of Siasync and see if the problem goes away? Here's a link: https://github.com/tbenz9/siasync/releases/tag/1.0.0-beta.2

Are the files in /volume1/Backup/TestSia.hbk changing frequently? In your debug example it's failing on a .lock file. lock files are typically being created and removed frequently. It's possible that Siasync scans the files properly but then when it tries to upload them the file has changed or is no longer there.

Are you able to reproduce the issue with other directories?

buxm commented 4 years ago

Hi, version 1.0.0. doesn't support -sync-only option. So I have run the command without it. What I get is:

2019/11/21 23:48:58 Connected to Sia 1.4.1.2 2019/11/21 23:48:58 50 contracts are ready for upload 2019/11/21 23:50:36 watching for changes to /volume1/Backup/TestSia1.hbk

then nothing happens any longer. Even running siac renter ls shows that my Sia storage is empty. Even adding the -debug option returns exactly the same result.

/volume1/Backup/TestSia.hbk was not changing when I ran the command. That is the target directory of a backup job I set up within Synology's backup tool. So .lock files are probably used by the tool while it's running, but the backup job is not scheduled to run regularly at the moment and was definitely not running when I ran siasync.

Finally, I tested on another directory containing only 4 pdf files. The outcome with 1.0.1 is as follows:

2019/11/22 00:00:06 Connected to Sia 1.4.1.2 2019/11/22 00:00:06 50 contracts are ready for upload 2019/11/22 00:00:08 Uploading files missing from Sia 2019/11/22 00:00:08 error uploading /volume1/Backup/TestSmall/Canne fumarie e condominio di edifici.pdf: upload failed: [unable to stat input file; stat /volume1/Backup/TestSmall/Canne fumarie e condominio di edifici.pdf: no such file or directory]

The outcome with 1.0.0 is as follows:

2019/11/22 00:01:43 Connected to Sia 1.4.1.2 2019/11/22 00:01:43 50 contracts are ready for upload 2019/11/22 00:01:43 watching for changes to /volume1/Backup/TestSmall/

and still siac renter ls shows 0 files on Sia storage.

So no luck in either case.

tbenz9 commented 4 years ago

I wrote a little utility to see if Go can stat the files. Are you familiar enough with Go to try this?

tbenz9@spartan1:/tmp$ cat main.go
package main

import (
        "fmt"
        "os"
)

func main() {
        fmt.Println("Trying to stat:", os.Args[1])
        fileStat, err := os.Stat(os.Args[1])
        if err != nil {
                fmt.Println(err)
                return
        }
        fmt.Println("Successfully stat'd:", fileStat.Name())
}

Then run it while passing in a single filename like this:

tbenz9@spartan1:/tmp$ go run main.go /tmp/test/@testfile
Trying to stat: /tmp/test/@testfile
Successfully stat'd: @testfile

Can you try running that on a few files that have been failing with Siasync?

buxm commented 4 years ago

Hi, $ go run main.go /volume1/Backup/TestSmall/Canne\ fumarie\ e\ condominio\ di\ edifici.pdf Trying to stat: /volume1/Backup/TestSmall/Canne fumarie e condominio di edifici.pdf Successfully stat'd: Canne fumarie e condominio di edifici.pdf

$ go run main.go /volume1/Backup/TestSia1.hbk/Config/@cand_file/123_1.cand_dup Trying to stat: /volume1/Backup/TestSia1.hbk/Config/@cand_file/123_1.cand_dup Successfully stat'd: 123_1.cand_dup

$ go run main.go /volume1/Backup/TestSia1.hbk/Pool/0/0/59.lock Trying to stat: /volume1/Backup/TestSia1.hbk/Pool/0/0/59.lock Successfully stat'd: 59.lock

It looks like it's working ok.

buxm commented 4 years ago

HI @tbenz9, I was wondering if this is just taking a while to investigate or if you don't think there is something to fix in Siasync. Many thanks!

tbenz9 commented 4 years ago

I haven't heard of this issue from other users, so I suspect its something related to your use case. It can probably be solved with a fix to SiaSync but I haven't had time (or priority) to dig into it yet. I was planning on keeping the issue open but I don't have plans to work on a fix in the immediate future. If you have resources I'd be happy to accept a Pull Request from you or someone else if they can come up with a fix before I get around to it.

buxm commented 4 years ago

Many thanks for your reply. I don't think I'll have the time (nor the skills, actually) to try to fix this. To be honest it's likely that I'll shortly clean up all the Sia stuff my NAS since I think at the moment it looks far too complicated to set up and maintain for my use case (I'll likely revisit it in 1 or 2 years to see how it has evolved). I'm happy to leave the issue open in case someone else comes across the same problem and/or someone wants to attempt a fix. Cheers!

TitaniumCoder477 commented 4 years ago

Today I attempted to setup siasync on my Nextcloud virtual machine in order to create an offsite copy of my data. I think I ran into the same issue described in this issue. Here is my setup:

Source data: /media/data/jwilmoth/files/Pictures root:root As root: ./siasync -debug true -password [redacted] -archive true -subfolder Pictures /media/data/jwilmoth/files/Pictures/

Each time I run siasync, it calculates the checksum for thousands of files and at that some random file (no repeat, no apparent pattern), it stops with an error like:

...
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-56-55.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-57-07.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-57-16.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-57-36.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-57-46.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-58-05.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-58-16.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-58-29.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-58-42.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-58-50.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-59-07.png
2020/05/03 02:41:38 [DEBUG] Calculating checksum for: /media/data/jwilmoth/files/Pictures/screenshots/shot_2014-03-17_13-59-13.png
2020/05/03 02:41:38 Uploading files missing from Sia
2020/05/03 02:41:38 [DEBUG] Uploading: /media/data/jwilmoth/files/Pictures/Clouds/20120531_180526.jpg
2020/05/03 02:41:38 error uploading /media/data/jwilmoth/files/Pictures/Clouds/20120531_180526.jpg: upload failed: [unable to stat input file; stat /media/data/jwilmoth/files/Pictures/Clouds/20120531_180526.jpg: permission denied]

Again, each time I run the command, the file is different. Root can most certainly access the files both via Bash and the main.go script:

root@wil-nextcloud-srv:/home/jwilmoth# go run main.go /media/data/jwilmoth/files/Pictures/Clouds/20120531_180526.jpg
Trying to stat: /media/data/jwilmoth/files/Pictures/Clouds/20120531_180526.jpg
Successfully stat'd: 20120531_180526.jpg

I cloned your git repo and poked through the code. I do not speak go, but since I dabble in Java, Kotlin, Bash, PowerShell, and many other languages, I was able to locate the place where siasync is producing error output, namely, line 407 of siafolder.go. I traced the variables back through the code, but nothing jumps out at me. I was thinking, based on the fact that the error isn't consistently one file, perhaps the issue is underlying access to the file system via API calls that are unable to handle the processing in adequate time? i.e. a back pressure situation? I am not familiar with the code enough at this point to know if this is a likely possibility or not.

Thoughts?