Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

vmbackupmanager: incompatibility issues with local FS on windows #4704

Closed
tekert opened this issue Jul 24, 2023 · 23 comments
Closed

vmbackupmanager: incompatibility issues with local FS on windows #4704

tekert opened this issue Jul 24, 2023 · 23 comments
Assignees
Labels
bug Something isn't working vmbackup

Comments

@tekert
Copy link

tekert commented Jul 24, 2023

Describe the bug

Can't create backups using vmbackupmanager.
vmbackup works correctly.

vmbackupmanager produces an error the moment a backup is scheduled to run.

To Reproduce

Executing this command:
vmbackupmanager-windows-amd64-prod.exe -eula -dst="fs://E:\Backups\victoria-metrics-backups" -storageDataPath=%VICTORIAMETRICS%\victoria-metrics-data -snapshot.createURL=http://localhost:8428/snapshot/create -maxBytesPerSecond=10485760 -keepLastDaily=2 -keepLastWeekly=1 -keepLastMonthly=3

Version

vmbackupmanager-20230602-121930-tags-v1.91.2-enterprise-0-g9c0ee3336

Logs

Copyright 2018-2022 VictoriaMetrics, Inc - All Rights Reserved.
For any questions please contact info@victoriametrics.com
2023-07-24T09:54:04.610-0300    info    VictoriaMetrics/lib/logger/flag.go:12   build version: vmbackupmanager-20230602-121930-tags-v1.91.2-enterprise-0-g9c0ee3336
2023-07-24T09:54:04.615-0300    info    VictoriaMetrics/lib/logger/flag.go:13   command-line flags
2023-07-24T09:54:04.615-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -dst="fs://E:\\Backups\\victoria-metrics-backups"
2023-07-24T09:54:04.615-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -eula="true"
2023-07-24T09:54:04.615-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -keepLastDaily="2"
2023-07-24T09:54:04.617-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -keepLastMonthly="3"
2023-07-24T09:54:04.618-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -keepLastWeekly="1"
2023-07-24T09:54:04.621-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -maxBytesPerSecond="10485760"
2023-07-24T09:54:04.622-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -snapshot.createURL="http://localhost:8428/snapshot/create"
2023-07-24T09:54:04.623-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -storageDataPath="C:\\Monitoring\\victoria-metrics\\victoria-metrics-data"
2023-07-24T09:54:04.634-0300    info    VictoriaMetrics/lib/httpserver/httpserver.go:96 starting http server at http://127.0.0.1:8300/
2023-07-24T09:54:04.639-0300    info    VictoriaMetrics/lib/httpserver/httpserver.go:97 pprof handlers are exposed at http://127.0.0.1:8300/debug/pprof/
2023-07-24T09:54:04.655-0300    info    VictoriaMetrics/app/vmbackupmanager/main.go:363 sleeping for 5m56s before the next backup
2023-07-24T10:00:01.609-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:116        starting backup from fslocal "C:\\Monitoring\\victoria-metrics\\victoria-metrics-data/snapshots/20230724130001-1774CEFA8C6D71E5" to fsremote "E:\\Backups\\victoria-metrics-backups\\latest" using origin fsnil
2023-07-24T10:00:01.634-0300    panic   VictoriaMetrics/lib/backup/fslocal/fslocal.go:74        BUG: unexpected prefix for file "C:\\Monitoring\\victoria-metrics\\victoria-metrics-data\\snapshots\\20230724130001-1774CEFA8C6D71E5\\data\\small\\2023_06\\176ED613C2B5507D\\index.bin"; want "C:\\Monitoring\\victoria-metrics\\victoria-metrics-data/snapshots/20230724130001-1774CEFA8C6D71E5\\"
panic: BUG: unexpected prefix for file "C:\\Monitoring\\victoria-metrics\\victoria-metrics-data\\snapshots\\20230724130001-1774CEFA8C6D71E5\\data\\small\\2023_06\\176ED613C2B5507D\\index.bin"; want "C:\\Monitoring\\victoria-metrics\\victoria-metrics-data/snapshots/20230724130001-1774CEFA8C6D71E5\\"

goroutine 9 [running]:
github.com/VictoriaMetrics/VictoriaMetrics/lib/logger.logMessage({0x181362d, 0x5}, {0xc000312780, 0x124}, 0x2?)
        github.com/VictoriaMetrics/VictoriaMetrics/lib/logger/logger.go:281 +0xa96
github.com/VictoriaMetrics/VictoriaMetrics/lib/logger.logLevelSkipframes(0x1, {0x181362d, 0x5}, {0x1844a5f?, 0x1628280?}, {0xc000013600?, 0x1628bc0?, 0xc000458220?})
        github.com/VictoriaMetrics/VictoriaMetrics/lib/logger/logger.go:138 +0x1a5
github.com/VictoriaMetrics/VictoriaMetrics/lib/logger.logLevel(...)
        github.com/VictoriaMetrics/VictoriaMetrics/lib/logger/logger.go:130
github.com/VictoriaMetrics/VictoriaMetrics/lib/logger.Panicf(...)
        github.com/VictoriaMetrics/VictoriaMetrics/lib/logger/logger.go:126
github.com/VictoriaMetrics/VictoriaMetrics/lib/backup/fslocal.(*FS).ListParts(0x1?)
        github.com/VictoriaMetrics/VictoriaMetrics/lib/backup/fslocal/fslocal.go:74 +0x2bd
github.com/VictoriaMetrics/VictoriaMetrics/lib/backup/actions.runBackup(0xc000086140, {0x1a17b10?, 0xc000458170}, {0x1a0f890?, 0x214b5e0}, 0xc00052a029?)
        github.com/VictoriaMetrics/VictoriaMetrics/lib/backup/actions/backup.go:118 +0x15e
github.com/VictoriaMetrics/VictoriaMetrics/lib/backup/actions.(*Backup).Run(0xc00052a000?)
        github.com/VictoriaMetrics/VictoriaMetrics/lib/backup/actions/backup.go:76 +0x1b4
main.(*backuper).makeBackup(0xc00006e0f0, 0xc000086140, {0x1816238?, 0xfffffcb9cf476000?})
        github.com/VictoriaMetrics/VictoriaMetrics/app/vmbackupmanager/main.go:496 +0x11e
main.(*backuper).run(0xc00006e0f0, {0x1a11da0, 0xc00006e0a0})
        github.com/VictoriaMetrics/VictoriaMetrics/app/vmbackupmanager/main.go:425 +0x20e
main.(*backuper).scheduleBackups(0xc00006e0f0, {0x1a11da0, 0xc00006e0a0})
        github.com/VictoriaMetrics/VictoriaMetrics/app/vmbackupmanager/main.go:372 +0x3a5
main.runBackupManager.func1()
        github.com/VictoriaMetrics/VictoriaMetrics/app/vmbackupmanager/main.go:150 +0x65
created by main.runBackupManager
        github.com/VictoriaMetrics/VictoriaMetrics/app/vmbackupmanager/main.go:148 +0x3aa

Screenshots

No response

Used command-line flags

-eula -dst="fs://E:\Backups\victoria-metrics-backups" -storageDataPath=%VICTORIAMETRICS%\victoria-metrics-data -snapshot.createURL=http://localhost:8428/snapshot/create -maxBytesPerSecond=10485760 -keepLastDaily=2 -keepLastWeekly=1 -keepLastMonthly=3

Additional information

Windows Server 2019
as Admin.

@tekert tekert added the bug Something isn't working label Jul 24, 2023
@zekker6 zekker6 self-assigned this Jul 24, 2023
@zekker6
Copy link
Contributor

zekker6 commented Jul 24, 2023

Hi @tekert
Could you check if this build works for you?
vmbackupmanager.zip

It includes a fix for paths join which creates a path with the following path victoria-metrics-data/snapshots/20230724130001-1774CEFA8C6D71E5 instead of victoria-metrics-data\\snapshots\\20230724130001-1774CEFA8C6D71E5 .

@tekert
Copy link
Author

tekert commented Jul 24, 2023

Yes, it there a way to execute the backup without waiting for the next hour?

@zekker6
Copy link
Contributor

zekker6 commented Jul 24, 2023

@tekert You can add -runOnStart=true to force creating a backup when vmbackupmanager is starting.

@tekert
Copy link
Author

tekert commented Jul 24, 2023

Seems it did something, but crashes after a succesfull backup.
here are the last lines from the log:


2023-07-24T10:32:07.837-0300    info    VictoriaMetrics/lib/backup/actions/copy.go:112  server-side copying part{path: "indexdb\\1773531B3EFAF259\\parts.json", file_size: 495, offset: 0, size: 495} from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07"
2023-07-24T10:32:07.847-0300    info    VictoriaMetrics/lib/backup/actions/copy.go:112  server-side copying part{path: "metadata\\minTimestampForCompositeIndex", file_size: 8, offset: 0, size: 8} from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07"
2023-07-24T10:32:07.883-0300    info    VictoriaMetrics/lib/backup/actions/copy.go:120  server-side copied 392 out of 392 parts from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07" in 1.2025221s
2023-07-24T10:32:07.883-0300    info    VictoriaMetrics/lib/backup/actions/copy.go:127  backup copy from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07" is complete; backed up 284063253 bytes in 1.308 seconds; deleted 0 bytes; server-side copied 284063253 bytes
2023-07-24T10:32:07.885-0300    info    VictoriaMetrics/app/vmbackupmanager/main.go:477 backup has been successfully created
2023-07-24T10:32:08.237-0300    error   VictoriaMetrics/app/vmbackupmanager/main.go:481 cannot update backups metrics: cannot get backups size: unexpected part name "daily\\2023-07-24\\data\\small\\2023_06\\176ED613C2B5507D\\index.bin"
2023-07-24T10:32:08.238-0300    fatal   VictoriaMetrics/app/vmbackupmanager/main.go:344 error creating backup: cannot get backups size: unexpected part name "daily\\2023-07-24\\data\\small\\2023_06\\176ED613C2B5507D\\index.bin"

@zekker6
Copy link
Contributor

zekker6 commented Jul 24, 2023

@tekert Thank you for the feedback!
Could you check this build?
vmbackupmanager.zip

@tekert
Copy link
Author

tekert commented Jul 24, 2023

No problem zek, wish i could help with the code.

Ran the new exe two times, one with a current backup of the last run, and another restarting victoria metrics, deleting all backups and any snapshot leftover, clean state, same error log.

Could the data from that file be corrupted for the backup but somehow causing no troubles for victoriametrics?

2023-07-24T11:41:25.555-0300    info    VictoriaMetrics/lib/backup/actions/copy.go:112  server-side copying part{path: "indexdb\\1773531B3EFAF259\\parts.json", file_size: 419, offset: 0, size: 419} from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07"
2023-07-24T11:41:25.555-0300    info    VictoriaMetrics/lib/backup/actions/copy.go:112  server-side copying part{path: "metadata\\minTimestampForCompositeIndex", file_size: 8, offset: 0, size: 8} from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07"
2023-07-24T11:41:25.558-0300    info    VictoriaMetrics/lib/backup/actions/copy.go:120  server-side copied 407 out of 407 parts from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07" in 516.4882ms
2023-07-24T11:41:25.558-0300    info    VictoriaMetrics/lib/backup/actions/copy.go:127  backup copy from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07" is complete; backed up 285235187 bytes in 0.588 seconds; deleted 0 bytes; server-side copied 285235187 bytes
2023-07-24T11:41:25.560-0300    info    VictoriaMetrics/app/vmbackupmanager/main.go:477 backup has been successfully created
2023-07-24T11:41:25.919-0300    error   VictoriaMetrics/app/vmbackupmanager/main.go:481 cannot update backups metrics: cannot get backups size: unexpected part name "daily\\2023-07-24\\data\\small\\2023_06\\176ED613C2B5507D\\index.bin"
2023-07-24T11:41:25.919-0300    fatal   VictoriaMetrics/app/vmbackupmanager/main.go:344 error creating backup: cannot get backups size: unexpected part name "daily\\2023-07-24\\data\\small\\2023_06\\176ED613C2B5507D\\index.bin"

@tekert
Copy link
Author

tekert commented Jul 24, 2023

Another run again results in another error log:

For any questions please contact info@victoriametrics.com
2023-07-24T11:46:25.697-0300    info    VictoriaMetrics/lib/logger/flag.go:12   build version: vmbackupmanager-20230724-142206-heads-issue-4704-0-g744f3f2466-dirty-3feed982
2023-07-24T11:46:25.700-0300    info    VictoriaMetrics/lib/logger/flag.go:13   command-line flags
2023-07-24T11:46:25.700-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -dst="fs://E:\\Backups\\victoria-metrics-backups"
2023-07-24T11:46:25.700-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -eula="true"
2023-07-24T11:46:25.700-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -keepLastDaily="2"
2023-07-24T11:46:25.700-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -keepLastMonthly="3"
2023-07-24T11:46:25.701-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -keepLastWeekly="1"
2023-07-24T11:46:25.701-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -loggerTimezone="America/Argentina/Buenos_Aires"
2023-07-24T11:46:25.701-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -maxBytesPerSecond="10485760"
2023-07-24T11:46:25.701-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -runOnStart="true"
2023-07-24T11:46:25.701-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -snapshot.createURL="http://localhost:8428/snapshot/create"
2023-07-24T11:46:25.701-0300    info    VictoriaMetrics/lib/logger/flag.go:20     -storageDataPath="C:\\Monitoring\\victoria-metrics\\victoria-metrics-data"
2023-07-24T11:46:25.702-0300    info    VictoriaMetrics/lib/httpserver/httpserver.go:96 starting http server at http://127.0.0.1:8300/
2023-07-24T11:46:25.702-0300    info    VictoriaMetrics/lib/httpserver/httpserver.go:97 pprof handlers are exposed at http://127.0.0.1:8300/debug/pprof/
2023-07-24T11:46:26.542-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:115        starting backup from fslocal "C:\\Monitoring\\victoria-metrics\\victoria-metrics-data\\snapshots\\20230724144626-1774D4A244C443DB" to fsremote "E:\\Backups\\victoria-metrics-backups\\latest" using origin fsnil
2023-07-24T11:46:26.585-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:121        obtained 392 parts from src fslocal "C:\\Monitoring\\victoria-metrics\\victoria-metrics-data\\snapshots\\20230724144626-1774D4A244C443DB"
2023-07-24T11:46:26.660-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:127        obtained 407 parts from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.660-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:133        obtained 0 parts from origin fsnil
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:140        deleting 31 parts from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF5\\metaindex.bin", file_size: 185, offset: 0, size: 185} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCEE\\values.bin", file_size: 15585, offset: 0, size: 15585} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCEE\\timestamps.bin", file_size: 1481, offset: 0, size: 1481} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCEE\\index.bin", file_size: 40934, offset: 0, size: 40934} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF5\\values.bin", file_size: 18176, offset: 0, size: 18176} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.666-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF7\\timestamps.bin", file_size: 3884, offset: 0, size: 3884} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF5\\timestamps.bin", file_size: 5046, offset: 0, size: 5046} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCEE\\metadata.json", file_size: 117, offset: 0, size: 117} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF5\\metadata.json", file_size: 117, offset: 0, size: 117} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF5\\index.bin", file_size: 41313, offset: 0, size: 41313} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCEE\\metaindex.bin", file_size: 197, offset: 0, size: 197} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.664-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF7\\index.bin", file_size: 41038, offset: 0, size: 41038} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.665-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF7\\metadata.json", file_size: 117, offset: 0, size: 117} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.666-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF7\\metaindex.bin", file_size: 193, offset: 0, size: 193} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.666-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF7\\values.bin", file_size: 13992, offset: 0, size: 13992} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.666-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF8\\index.bin", file_size: 32052, offset: 0, size: 32052} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.667-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF8\\metadata.json", file_size: 116, offset: 0, size: 116} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.667-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF8\\metaindex.bin", file_size: 148, offset: 0, size: 148} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.667-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF8\\timestamps.bin", file_size: 540, offset: 0, size: 540} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.668-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774CEFA993DCCF8\\values.bin", file_size: 570, offset: 0, size: 570} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.668-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C609\\index.bin", file_size: 31080, offset: 0, size: 31080} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.668-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C609\\metadata.json", file_size: 116, offset: 0, size: 116} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.668-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C609\\metaindex.bin", file_size: 137, offset: 0, size: 137} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.669-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C609\\timestamps.bin", file_size: 504, offset: 0, size: 504} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.669-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C609\\values.bin", file_size: 2418, offset: 0, size: 2418} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.669-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C60C\\index.bin", file_size: 39162, offset: 0, size: 39162} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.669-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C60C\\metadata.json", file_size: 117, offset: 0, size: 117} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.670-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C60C\\metaindex.bin", file_size: 182, offset: 0, size: 182} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.670-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C60C\\timestamps.bin", file_size: 1161, offset: 0, size: 1161} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.670-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\1774D4A25867C60C\\values.bin", file_size: 9270, offset: 0, size: 9270} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.670-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:143        deleting part{path: "data\\small\\2023_07\\parts.json", file_size: 552, offset: 0, size: 552} from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest"
2023-07-24T11:46:26.680-0300    info    VictoriaMetrics/lib/backup/actions/backup.go:151        deleted 31 out of 31 parts from dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest" in 16.4946ms
2023-07-24T11:46:26.827-0300    fatal   VictoriaMetrics/app/vmbackupmanager/main.go:344 error creating backup: cannot create backup: cannot remove empty directories at dst fsremote "E:\\Backups\\victoria-metrics-backups\\latest": cannot list "E:\\Backups\\victoria-metrics-backups\\latest\\data": cannot list "E:\\Backups\\victoria-metrics-backups\\latest\\data\\small": cannot list "E:\\Backups\\victoria-metrics-backups\\latest\\data\\small\\2023_07": cannot list "E:\\Backups\\victoria-metrics-backups\\latest\\data\\small\\2023_07\\1774CEFA993DCCEE": cannot list "E:\\Backups\\victoria-metrics-backups\\latest\\data\\small\\2023_07\\1774CEFA993DCCEE\\index.bin": cannot remove "E:\\Backups\\victoria-metrics-backups\\latest\\data\\small\\2023_07\\1774CEFA993DCCEE\\index.bin": remove E:\Backups\victoria-metrics-backups\latest\data\small\2023_07\1774CEFA993DCCEE\index.bin: The process cannot access the file because it is being used by another process.

@zekker6
Copy link
Contributor

zekker6 commented Jul 24, 2023

@tekert Thanks a lot for your testing. It seems to me like it will be better to set up a proper testing environment for those fixes and verify it works after fixing all the issues.
We'll post updates in this issue once this will be ready

@zekker6 zekker6 changed the title vmbackupmanager (unexpected prefix for file) vmbackupmanager: incompatibility issues with local FS on windows Jul 24, 2023
@tekert
Copy link
Author

tekert commented Jul 24, 2023

I could send you the data in private, is just test data from the last month, its only 142mb.

@zekker6
Copy link
Contributor

zekker6 commented Jul 24, 2023

@tekert Thanks, this will not be necessary because we have our benchmark which can generate data for testing.
Also, those issues are not related to data itself but to a way we handle file operations in vmbackupmanager when running on Windows.

@hagen1778 hagen1778 added the TBD To Be Done label Jul 26, 2023
@zekker6
Copy link
Contributor

zekker6 commented Jul 27, 2023

@tekert Hello! May I ask you to test this build and see if that works for you?
vmbackupmanager.zip

We've tested this internally and it seems to be working well, wanted to confirm that it works in your case as well.

@tekert
Copy link
Author

tekert commented Jul 27, 2023

@zekker6
Hi zek, yep, seems everything is working now: Thanks! 😃

Executing same command as before: ✔️

... <long list of files>
...
2023-07-27T15:55:36.138Z        info    VictoriaMetrics/lib/backup/actions/copy.go:120  server-side copied 382 out of 382 parts from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07" in 1.604384s
2023-07-27T15:55:36.138Z        info    VictoriaMetrics/lib/backup/actions/copy.go:127  backup copy from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07" is complete; backed up 310503211 bytes in 1.693 seconds; deleted 0 bytes; server-side copied 310503211 bytes
2023-07-27T15:55:36.140Z        info    VictoriaMetrics/app/vmbackupmanager/main.go:477 backup has been successfully created
2023-07-27T15:55:36.486Z        info    VictoriaMetrics/app/vmbackupmanager/retention.go:123    daily backups to delete []
2023-07-27T15:55:36.768Z        info    VictoriaMetrics/app/vmbackupmanager/retention.go:123    weekly backups to delete []
2023-07-27T15:55:37.045Z        info    VictoriaMetrics/app/vmbackupmanager/retention.go:123    monthly backups to delete []
2023-07-27T15:55:37.581Z        info    VictoriaMetrics/app/vmbackupmanager/main.go:363 sleeping for 4m23s before the next backup

Shutting down the service (Control+C) and restarting it also works correctly. ✔️

...
2023-07-27T15:58:55.182Z        info    VictoriaMetrics/lib/backup/actions/copy.go:120  server-side copied 17 out of 17 parts from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07" in 56.4529ms
2023-07-27T15:58:55.186Z        info    VictoriaMetrics/lib/backup/actions/copy.go:127  backup copy from src fsremote "E:\\Backups\\victoria-metrics-backups\\latest" to dst fsremote "E:\\Backups\\victoria-metrics-backups\\monthly\\2023-07" is complete; backed up 310626495 bytes in 0.287 seconds; deleted 876 bytes; server-side copied 124160 bytes
2023-07-27T15:58:55.189Z        info    VictoriaMetrics/app/vmbackupmanager/main.go:477 backup has been successfully created
2023-07-27T15:58:55.492Z        info    VictoriaMetrics/app/vmbackupmanager/retention.go:123    daily backups to delete []
2023-07-27T15:58:55.779Z        info    VictoriaMetrics/app/vmbackupmanager/retention.go:123    weekly backups to delete []
2023-07-27T15:58:56.065Z        info    VictoriaMetrics/app/vmbackupmanager/retention.go:123    monthly backups to delete []
2023-07-27T15:58:56.670Z        info    VictoriaMetrics/app/vmbackupmanager/main.go:363 sleeping for 1m4s before the next backup

Seems everything is working.

@tekert
Copy link
Author

tekert commented Jul 27, 2023

Oh, i noticed snapshots are not being deleted after the backup. It's that intended?

@zekker6
Copy link
Contributor

zekker6 commented Jul 27, 2023

Snapshots should be renamed to something containing must-remove in its name. Is it the case?

Windows does not allow deleting files in case any other process is using it. And this is frequently the case with snapshots since snapshots in VM are based on creating symlinks, so the file can still be in use.
In order to avoid issues with deleting such files on Windows VM will rename directories to a special name with must-remove and will delete those files when the DB will be restarted.

@tekert
Copy link
Author

tekert commented Jul 27, 2023

Ouch, false alarm, an additional snapshot from some testing remained on the system and mistaked it for a backup, doing delete_all and restarting the previous test confirms %VMDATA%/snapshots are deleted but %VMDATA%/data/small/snapshots have those must-removes, so all good.
is there a way to delete the must-removes periodically, maybe a custom script can do it?

@zekker6
Copy link
Contributor

zekker6 commented Jul 27, 2023

Unfortunately the only option to remove those and be sure that this will work correctly is to periodically restart the VM.

@tekert
Copy link
Author

tekert commented Jul 27, 2023

I was thinking, since the write interval from memory can be configured, maybe handles can be restarted internally and resume writes after?

@zekker6
Copy link
Contributor

zekker6 commented Jul 27, 2023

Apart writing data from memory storage can also perform:

  • background merges
  • reading data for query processing

So the problem with deleting even symlinked files is that this file can be opened for reading at query execution path.
This means that in order to be absolutely sure that we will not get file is already used by another process error in windows we need to:

  • stop query processing
  • stop writing new data
  • stop background merges process.

This seems like we need to stop all DB operations anyway, very similar to what happens on graceful shutdown during restart. That's why we decided not to implement this as a built-in functionality to keep code base simpler.

@tekert
Copy link
Author

tekert commented Jul 27, 2023

I understand, i see, thanks for the explanations zek, I'll try to schedule a restart because last time i checked the data folder increased 4x in size for the last month.
I can close this as resolved if everything is in order.

@zekker6
Copy link
Contributor

zekker6 commented Jul 28, 2023

@tekert Lets leave this issue open until fixes which are included into builds I've provided will be merged into upstream version and released. We'll close this issue once those fixes will be released.

zekker6 added a commit that referenced this issue Aug 1, 2023
Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>
zekker6 added a commit that referenced this issue Aug 1, 2023
Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>
zekker6 added a commit that referenced this issue Aug 1, 2023
Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>
@tekert
Copy link
Author

tekert commented Aug 3, 2023

@zekker6 I was wondering if the handles for those hardlinked files could be opened with FILE_SHARE_DELETE access from win32 api: https://learn.microsoft.com/en-us/windows/win32/api/fileapi/nf-fileapi-createfilea#file_share_delete
Maybe hardlinks can be deleted with that flag on windows.

@f41gh7
Copy link
Contributor

f41gh7 commented Aug 7, 2023

@zekker6 I was wondering if the handles for those hardlinked files could be opened with FILE_SHARE_DELETE access from win32 api: https://learn.microsoft.com/en-us/windows/win32/api/fileapi/nf-fileapi-createfilea#file_share_delete Maybe hardlinks can be deleted with that flag on windows.

Indeed, such API exists with new version of Windows. But it extremely unreliable.

It has few exclusions, one of them - You cannot delete mapped files. It makes this API unusable for VictoriaMetrics, since it mostly open files with MMAP. I suppose, mapping propagated to the hard-linked files.

f41gh7 pushed a commit that referenced this issue Aug 10, 2023
Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>
valyala pushed a commit that referenced this issue Aug 11, 2023
* app/vmbackupmanager/storage: fix path join for windows

See: #4704

Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>

* lib/backup: fixes for windows support

- close dir before running os.RemoveAll. Windows FS does not allow to delete directory before all handles will be closed.

- add path "normalization" for local FS to use the same format of paths for both *unix and Windows

See #4704

Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>

---------

Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>
valyala pushed a commit that referenced this issue Aug 11, 2023
Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>
valyala pushed a commit that referenced this issue Aug 11, 2023
* app/vmbackupmanager/storage: fix path join for windows

See: #4704

Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>

* lib/backup: fixes for windows support

- close dir before running os.RemoveAll. Windows FS does not allow to delete directory before all handles will be closed.

- add path "normalization" for local FS to use the same format of paths for both *unix and Windows

See #4704

Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>

---------

Signed-off-by: Zakhar Bessarab <z.bessarab@victoriametrics.com>
@valyala valyala added vmbackup and removed TBD To Be Done labels Aug 12, 2023
@valyala
Copy link
Collaborator

valyala commented Aug 12, 2023

FYI, vmbackupmanager should properly make backups to local filesystem on Windows starting from v1.93.0. Closing the issue as fixed then.

@valyala valyala closed this as completed Aug 12, 2023
valyala added a commit that referenced this issue Sep 18, 2023
…eparators at Part.Path

Previously Part.Path could contain `\` directory separators on Windows OS,
which could result in incorrect filepaths generation when making backups at object storage.

Updates #4704

This is a follow-up for f2df8ad
valyala added a commit that referenced this issue Sep 18, 2023
…eparators at Part.Path

Previously Part.Path could contain `\` directory separators on Windows OS,
which could result in incorrect filepaths generation when making backups at object storage.

Updates #4704

This is a follow-up for f2df8ad
valyala added a commit that referenced this issue Sep 18, 2023
…eparators at Part.Path

Previously Part.Path could contain `\` directory separators on Windows OS,
which could result in incorrect filepaths generation when making backups at object storage.

Updates #4704

This is a follow-up for f2df8ad
valyala added a commit that referenced this issue Sep 19, 2023
…eparators at Part.Path

Previously Part.Path could contain `\` directory separators on Windows OS,
which could result in incorrect filepaths generation when making backups at object storage.

Updates #4704

This is a follow-up for f2df8ad
AndrewChubatiuk pushed a commit to AndrewChubatiuk/VictoriaMetrics that referenced this issue Oct 3, 2023
…eparators at Part.Path

Previously Part.Path could contain `\` directory separators on Windows OS,
which could result in incorrect filepaths generation when making backups at object storage.

Updates VictoriaMetrics#4704

This is a follow-up for f2df8ad
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working vmbackup
Projects
None yet
Development

No branches or pull requests

5 participants