`restic ls` lists some files, then sudden EOF

I’m unable to reproduce this with other repositories at the moment, but I’ll do my best to document this and I’m hoping to gain some insight as to why this is happening.

Running restic --cleanup-cache --cache-dir ../mycache ls a278f... --long successfully lists files in the snapshot, but only until it prints 13676635 bytes (80655 lines, plus header row). Then restic prints EOF to stderr and exits with status 1.

I can’t seem to figure out where the EOF is coming from. I’ve tried various repositories and have not been able to reproduce it between local, LAN, and remote destinations. I searched the code base and it doesn’t appear to be one that restic itself is fabricating, but comes from the Go standard lib.

However, the behavior with this repository is consistent – every time. I ran restic check and “no errors were found” (just some extra packs that could be cleaned up with prune).

It’s quite possible this has something to do with the way I’m “holding” restic, but does any of this look familiar to anyone?

(More info: it takes about 7 seconds to get to EOF with my slow network speeds, and the repository takes about 65 GB on disk.)

UPDATE: It might have something to do with using rclone serve restic as the backend. I’m not seeing any errors from rclone yet, but still investigating. The actual backend storage that rclone is connecting to seems irrelevant, since I can reproduce this behavior on multiple cloud storage providers.

UPDATE 2: I can’t even reproduce it with any other repos using rclone serve restic – so this issue is really isolated I think. Feel free to share any thoughts if you have them, but at this point I’m mostly self-documenting this for science’ sake.

Uh, that’s odd. Build restic with the debug tag and write a log, maybe that’ll tell us what’s going on. At least you have a repo where the issue is reproducible :slight_smile:

Ah, I forgot about that feature – thanks for the reminder!

Here’s the end of the log (I started copying from a random line near the end of the output):

|2018/08/08 06:03:10 repository/repository.go:119|repository.(*Repository).loadBlob|1|load tree with id 0f892680150a5b1c4705ed163f975ff840116fd8bd9b1227461612f52f5e151f (buf len 1863, cap 1895)|
|---|---|---|---|
|2018/08/08 06:03:10 repository/repository.go:133|repository.(*Repository).loadBlob|1|blob tree/0f892680150a5b1c4705ed163f975ff840116fd8bd9b1227461612f52f5e151f found: <Blob (tree) 0f892680, offset 3610804, length 1895>|
|2018/08/08 06:03:10 restic/readerat.go:27|restic.ReadAt|1|ReadAt(<data/c86869d2c7>) at 3610804, len 1895|
|2018/08/08 06:03:10 cache/backend.go:158|cache.(*Backend).Load|1|Load(<data/c86869d2c7>, 1895, 3610804) from cache|
|2018/08/08 06:03:10 cache/file.go:44|cache.(*Cache).Load|1|Load from cache: <data/c86869d2c7>|
|2018/08/08 06:03:10 restic/readerat.go:38|restic.ReadAt|1|ReadAt(<data/c86869d2c7>) ReadFull returned 1895 bytes|
|2018/08/08 06:03:10 repository/repository.go:650|repository.(*Repository).LoadTree|1|load tree 5cd482940556cda0c7d6b84f617d299c3c581750a1b5b358c678994c8a6b2632|
|2018/08/08 06:03:10 repository/repository.go:657|repository.(*Repository).LoadTree|1|size is 2401, create buffer|
|2018/08/08 06:03:10 repository/repository.go:119|repository.(*Repository).loadBlob|1|load tree with id 5cd482940556cda0c7d6b84f617d299c3c581750a1b5b358c678994c8a6b2632 (buf len 2401, cap 2433)|
|2018/08/08 06:03:10 repository/repository.go:133|repository.(*Repository).loadBlob|1|blob tree/5cd482940556cda0c7d6b84f617d299c3c581750a1b5b358c678994c8a6b2632 found: <Blob (tree) 5cd48294, offset 2698911, length 2433>|
|2018/08/08 06:03:10 restic/readerat.go:27|restic.ReadAt|1|ReadAt(<data/781ad7938d>) at 2698911, len 2433|
|2018/08/08 06:03:10 cache/backend.go:158|cache.(*Backend).Load|1|Load(<data/781ad7938d>, 2433, 2698911) from cache|
|2018/08/08 06:03:10 cache/file.go:44|cache.(*Cache).Load|1|Load from cache: <data/781ad7938d>|
|2018/08/08 06:03:10 repository/repository.go:150|repository.(*Repository).loadBlob|1|error loading blob <Blob (tree) 5cd48294, offset 2698911, length 2433>: EOF|
|2018/08/08 06:03:10 restic/lock.go:118|main.unlockAll|1|unlocking 0 locks|

(Huh, weirdly the tabs pasted as pipe characters.)

The second-to-last line has the EOF.

Looks like it’s loading a blob or something from the cache.

UPDATE: After deleting the restic cache and running the restic ls command again, it is definitely going longer now! No EOF at the usual spot. It’s been running for 160 seconds and still going, and I have to head out the door, but it looks like it’s working. … UPDATE 2: Yeah it finished after 5 minutes.

Question: is there a way to get restic ls to print only files in a certain directory or tree (and not subfolders)? Right now the file listing takes way too long for just wanting to see the files in a certain folder.

That looks like a cache issue, where the cache contains a truncated file. We should track this as a bug and correct restic’s behavior.

1 Like

Great – will do that soon!

Also, will you be open to a PR to limit restic ls to just a certain directory/tree? Ideally we could get a list of files for just a certain directory without having to filter the entire set… (is there a way to do that restriction internally, or would ls have to scan the entire set anyway?)

1 Like