resticprofile icon indicating copy to clipboard operation
resticprofile copied to clipboard

Mangled output

Open Gaibhne opened this issue 2 years ago • 6 comments

I was presented with what I am guessing is a problem with either reading or outputting the log from restic:

C:\restic>resticprofile.exe -n myprofile backup
2023/04/24 08:51:50 using configuration file: profiles.yaml
2023/04/24 08:51:50 profile 'myprofile': starting 'backup'
open repository
repository 081711bd opened (version 2, compression level max)
lock repository
using parent snapshot 0a592b20
load index files
start scan on [c:\]
start backup on [c:\]
creating VSS snapshot for [c:\]
successfully created snapshot for [c:\]

ccess is denied.

dat: Access is denied.

dat.LOG1: Access is denied.

dat.LOG2: Access is denied.
scan finished in 71.440s: 64313 files, 22.441 GiB

That does not seem like it should look like that.

Gaibhne avatar Apr 24 '23 07:04 Gaibhne

Hi @Gaibhne, in order to locate the problem, could you please do the following:

  • run C:\restic>resticprofile.exe -n myprofile --dry-run backup
  • collect the restic backup command line from the output
  • replace *** with the real password (if necessary)
  • run the restic command directly and check if the output differs. If so please share the output and the command line without any confidential parts

jkellerer avatar Apr 24 '23 09:04 jkellerer

Ah, it seems there is what I would think is a rather severe bug with excludes - parameters are given to restic without quotes, so spaces in file names appear to cause total chaos. I have since updated my config, and can't reproduce the exact error above, but I would guess that it's related. Is the exclude: option just not usable at all with file/path names containing spaces ? I haven't tried on Linux, but I would expect it to be the same there.

Gaibhne avatar Apr 24 '23 13:04 Gaibhne

Escaping differs for Linux and Windows, however dry-run may not show the correct output with escaping on Windows since we pass every argument (as list) to the underlying exec call and let it escape it, but for Linux this does not work due to calls like bash -c "command with params" (shell expects a single argument of the entire command line), in this case escaping (or quoting) happens internally.

So with other words, it depends on the env and this is not too great when debugging things like this. We might need a way to feedback the arguments that were really received (e.g. with an own echo command, that we already use in integration tests but it is not available for dry-run).

While this could have caused a problem, I'm not sure if it would create truncated output. Issues in escaping excludes would more likely either create a complete backup failure or break the excludes (e.g. include them instead).

Could you check if you can reproduce the problem when quoting dry-run output manually?

jkellerer avatar Apr 24 '23 13:04 jkellerer

You are correct, I confirmed that while the copied --dry-run call doesn't treat the spaces correctly, the actual command does. I am at a loss then, unable to reproduce it. I will leave this issue open and see if it happens again during the day and report back.

Gaibhne avatar Apr 24 '23 13:04 Gaibhne

this is still happening, I don't think escaping of the command is the issue, since the problem is in how the output of the command is displayed and the errors are not caused by the exclude options

resticprofile:

2024/06/24 06:00:20 using configuration file: profiles.yaml
2024/06/24 06:00:20 profile 'default': starting 'backup'
open repository
repository bec98e81 opened (version 2, compression level auto)
found 1 old cache directories in C:\windows\system32\config\systemprofile\AppData\Local\restic, run `restic cache --clea
nup` to remove them
lock repository
using parent snapshot 6f7c6295
load index files
[0:00] 100.00%  4 / 4 index files loaded
start scan on [C:\(games)\(saves)\ C:\_work\ C:\Users\Max\ C:\Program Files (x86)\Steam\userdata\ D:\Media\Books\ D:\Med
ia\Pictures\]
start backup on [C:\(games)\(saves)\ C:\_work\ C:\Users\Max\ C:\Program Files (x86)\Steam\userdata\ D:\Media\Books\ D:\M
edia\Pictures\]
creating VSS snapshot for [c:\]


t is being used by another process.

ause it is being used by another process.nd/backend.log

.

.

without resticprofile:

restic backup "--iexclude=C:\\_work\\**\\.venv" --iexclude=C:\\_work\\Dropbox\\.dropbox.cache "--iexclude=C:\\Users\\Max\\**\\*cache\\" "--iexclude=C:\\Users\\Max\\.conda" --iexclude=C:\\Users\\Max\\.local\\pipx\\venvs --iexclude=C:\\Users\\Max\\.ssh\\agent.sock --iexclude=C:\\Users\\Max\\.virtualenvs\\ --iexclude=C:\\Users\\Max\\.vscode\\extensions "--iexclude=C:\\Users\\Max\\AppData\\Local\\ACD Systems\\Catalogs\\**\\Thumb*.fpt" --iexclude=C:\\Users\\Max\\AppData\\Local\\Google\\Chrome\\ --iexclude=C:\\Users\\Max\\AppData\\Local\\conda\\ --iexclude=C:\\Users\\Max\\AppData\\Local\\CrashDumps\\ --iexclude=C:\\Users\\Max\\AppData\\Local\\Cryptomator\\ipc.socket --iexclude=C:\\Users\\Max\\AppData\\Local\\Microsoft\\Edge\\ --iexclude=C:\\Users\\Max\\AppData\\Local\\Microsoft\\WindowsApps\\ --iexclude=C:\\Users\\Max\\AppData\\Local\\Packages\\ --iexclude=C:\\Users\\Max\\AppData\\Local\\Temp "--iexclude=C:\\Users\\Max\\Documents\\My Games\\Tabletop Simulator\\Mods\\" --password-file=password.txt --repo=sftp://[email protected]:11067//backups/desktop --use-fs-snapshot --verbose C:\\(games)\\(saves)\\ C:\\_work\\ C:\\Users\\Max\\ "C:\\Program Files (x86)\\Steam\\userdata\\" D:\\Media\\Books\\ D:\\Media\\Pictures\\
open repository
repository bec98e81 opened (version 2, compression level auto)
lock repository
using parent snapshot 57c18508
load index files
[0:00] 100.00%  5 / 5 index files loaded
start scan on [C:\\(games)\\(saves)\\ C:\\_work\\ C:\\Users\\Max\\ C:\\Program Files (x86)\\Steam\\userdata\ D:\\Media\\Books\\ D:\\Media\\Pictures\\]
start backup on [C:\\(games)\\(saves)\\ C:\\_work\\ C:\\Users\\Max\\ C:\\Program Files (x86)\\Steam\\userdata\ D:\\Media\\Books\\ D:\\Media\\Pictures\\]
creating VSS snapshot for [c:\]
error: failed to create snapshot for [c:\]: VSS error: async operation failed: VSS_E_INSUFFICIENT_STORAGE (0x8004231f)
error: open C:\Users\Max\AppData\Local\Comms\UnistoreDB\USS.jtx: The process cannot access the file because it is being used by another process.
error: open C:\Users\Max\AppData\Local\Comms\UnistoreDB\store.jfm: The process cannot access the file because it is being used by another process.
error: open C:\Users\Max\AppData\Local\Comms\UnistoreDB\store.vol: The process cannot access the file because it is being used by another process.
error: open C:\Users\Max\AppData\Local\Comms\UnistoreDB\tmp.edb: The process cannot access the file because it is being used by another process.
signal interrupt received, cleaning up

using restic 0.16.4, resticprofile version 0.26.0 on windows 10

mkatsevVR avatar Jun 24 '24 14:06 mkatsevVR

if I use -l flag to redirect the output to a file, it looks normal, so something is messed up with printing to console specifically

mkatsevVR avatar Jun 24 '24 14:06 mkatsevVR