2024/04/07 22:26:26 restic/main.go:106 main.main 1 main []string{"${REDACTED}", "restore", "latest", "--target", "/tmp/foo1"} 2024/04/07 22:26:26 restic/main.go:107 main.main 1 restic 0.16.4 compiled with go1.22.1 on linux/amd64 2024/04/07 22:26:26 restic/cmd_restore.go:151 main.runRestore 1 restore latest to /tmp/foo1 2024/04/07 22:26:26 restic/global.go:575 main.open 1 parsing location /tmp/restic 2024/04/07 22:26:26 restic/global.go:569 main.parseConfig 1 opening local repository at &local.Config{Path:"/tmp/restic", Layout:"", Connections:0x2} 2024/04/07 22:26:26 local/local.go:58 local.Open 1 open local backend at /tmp/restic (layout "") 2024/04/07 22:26:26 layout/layout.go:139 layout.ParseLayout 1 parse layout string "" for backend at /tmp/restic 2024/04/07 22:26:26 layout/layout.go:99 layout.DetectLayout 1 detect layout at /tmp/restic 2024/04/07 22:26:26 layout/layout.go:117 layout.DetectLayout 1 found default layout at /tmp/restic 2024/04/07 22:26:26 layout/layout.go:163 layout.ParseLayout 1 layout detected: 2024/04/07 22:26:26 local/local.go:47 local.open 1 using (0o600 file, 0o700 dir) permissions 2024/04/07 22:26:26 logger/log.go:52 logger.(*Backend).Stat 1 Stat() 2024/04/07 22:26:26 sema/semaphore.go:27 sema.semaphore.GetToken 1 acquired token 2024/04/07 22:26:26 logger/log.go:54 logger.(*Backend).Stat 1 stat err 2024/04/07 22:26:26 index/index.go:382 index.(*Index).Finalize 1 finalizing index 2024/04/07 22:26:26 logger/log.go:59 logger.(*Backend).List 1 List(key) 2024/04/07 22:26:26 repository/key.go:145 repository.SearchKey.func1 1 trying key "5ee4c44c8e933fd558cf2078e2eb0568860965d2f5770a1e16b2b42e724b92f8" 2024/04/07 22:26:26 logger/log.go:45 logger.(*Backend).Load 1 Load(, length 0, offset 0) 2024/04/07 22:26:26 sema/semaphore.go:27 sema.semaphore.GetToken 1 acquired token 2024/04/07 22:26:26 logger/log.go:47 logger.(*Backend).Load 1 load err 2024/04/07 22:26:27 repository/key.go:158 repository.SearchKey.func1 1 successfully opened key 5ee4c44c8e933fd558cf2078e2eb0568860965d2f5770a1e16b2b42e724b92f8 2024/04/07 22:26:27 logger/log.go:61 logger.(*Backend).List 1 list err 2024/04/07 22:26:27 repository/repository.go:177 repository.(*Repository).LoadUnpacked 1 load config with id 0000000000000000000000000000000000000000000000000000000000000000 2024/04/07 22:26:27 logger/log.go:45 logger.(*Backend).Load 1 Load(, length 0, offset 0) 2024/04/07 22:26:27 sema/semaphore.go:27 sema.semaphore.GetToken 1 acquired token 2024/04/07 22:26:27 logger/log.go:47 logger.(*Backend).Load 1 load err 2024/04/07 22:26:27 cache/cache.go:95 cache.New 1 using cache dir ${REDACTED} 2024/04/07 22:26:27 repository/repository.go:165 repository.(*Repository).UseCache 1 using cache 2024/04/07 22:26:27 cache/cache.go:219 cache.OlderThan 1 0 old cache dirs found 2024/04/07 22:26:27 logger/log.go:59 logger.(*Backend).List 12 List(lock) 2024/04/07 22:26:27 logger/log.go:61 logger.(*Backend).List 12 list err 2024/04/07 22:26:27 restic/json.go:25 restic.SaveJSONUnpacked 1 save new blob lock 2024/04/07 22:26:27 logger/log.go:30 logger.(*Backend).Save 1 Save(, 179) 2024/04/07 22:26:27 logger/log.go:32 logger.(*Backend).Save 1 save err 2024/04/07 22:26:27 repository/repository.go:542 repository.(*Repository).SaveUnpacked 1 blob saved 2024/04/07 22:26:27 logger/log.go:59 logger.(*Backend).List 15 List(lock) 2024/04/07 22:26:27 logger/log.go:61 logger.(*Backend).List 15 list err 2024/04/07 22:26:27 restic/parallel.go:44 restic.ParallelList.func2 66 worker got file lock/ec80ff39 2024/04/07 22:26:27 restic/lock.go:104 main.lockRepository 1 create lock 0xc000201960 (exclusive false) 2024/04/07 22:26:27 logger/log.go:59 logger.(*Backend).List 69 List(snapshot) 2024/04/07 22:26:27 restic/lock.go:135 main.refreshLocks 67 start 2024/04/07 22:26:27 logger/log.go:61 logger.(*Backend).List 69 list err 2024/04/07 22:26:27 restic/parallel.go:44 restic.ParallelList.func2 71 worker got file snapshot/caeea779 2024/04/07 22:26:27 restic/parallel.go:44 restic.ParallelList.func2 70 worker got file snapshot/c12f546c 2024/04/07 22:26:27 repository/repository.go:177 repository.(*Repository).LoadUnpacked 71 load snapshot with id caeea779e2d178c8aa71efa658754481d24b8b6ce4d146c1adb84fb8ddd8aefa 2024/04/07 22:26:27 repository/repository.go:177 repository.(*Repository).LoadUnpacked 70 load snapshot with id c12f546caab0a99753a18c6fab5c0d4a8e1b77a6496d1a8d422e288ad50862ad 2024/04/07 22:26:27 cache/file.go:38 cache.(*Cache).load 71 Load(, 0, 0) from cache 2024/04/07 22:26:27 cache/file.go:38 cache.(*Cache).load 70 Load(, 0, 0) from cache 2024/04/07 22:26:27 restic/snapshot.go:183 restic.(*Snapshot).HasTagList 71 testing snapshot with tags [] against list: [] 2024/04/07 22:26:27 repository/repository.go:645 repository.(*Repository).LoadIndex 1 Loading index 2024/04/07 22:26:27 logger/log.go:59 logger.(*Backend).List 1 List(index) 2024/04/07 22:26:27 logger/log.go:61 logger.(*Backend).List 1 list err 2024/04/07 22:26:27 restic/parallel.go:44 restic.ParallelList.func2 87 worker got file index/c0cd0eed 2024/04/07 22:26:27 restic/parallel.go:44 restic.ParallelList.func2 63 worker got file index/c68373ad 2024/04/07 22:26:27 repository/repository.go:177 repository.(*Repository).LoadUnpacked 87 load index with id c0cd0eedb4024267c700ae2d4eebc0893c4a40a95130b4180ccce38a4e5cc80b 2024/04/07 22:26:27 cache/file.go:38 cache.(*Cache).load 87 Load(, 0, 0) from cache 2024/04/07 22:26:27 repository/repository.go:177 repository.(*Repository).LoadUnpacked 63 load index with id c68373adb1d8b3e6e975b6a7866e3a6816b463d2f89ae26fb3820970f0b04071 2024/04/07 22:26:27 cache/file.go:38 cache.(*Cache).load 63 Load(, 0, 0) from cache 2024/04/07 22:26:27 index/index.go:510 index.DecodeIndex 87 Start decoding index 2024/04/07 22:26:27 index/index.go:510 index.DecodeIndex 63 Start decoding index 2024/04/07 22:26:27 index/index.go:545 index.DecodeIndex 87 done 2024/04/07 22:26:27 index/index.go:545 index.DecodeIndex 63 done 2024/04/07 22:26:27 repository/repository.go:785 repository.(*Repository).prepareCache 1 prepare cache with 2 index files 2024/04/07 22:26:27 cache/file.go:153 cache.(*Cache).Clear 1 Clearing cache for index: 2 valid files 2024/04/07 22:26:27 cache/file.go:153 cache.(*Cache).Clear 1 Clearing cache for data: 4 valid files 2024/04/07 22:26:27 restorer/restorer.go:238 restorer.(*Restorer).RestoreTo 1 first pass for "/tmp/foo1" 2024/04/07 22:26:27 restorer/restorer.go:56 restorer.(*Restorer).traverseTree 1 /tmp/foo1 / 15861b4443b66ab2c51c38d26dc7e79abc0c89fe7a83184340946ebac54d6d3b 2024/04/07 22:26:27 restic/tree.go:113 restic.LoadTree 1 load tree 15861b4443b66ab2c51c38d26dc7e79abc0c89fe7a83184340946ebac54d6d3b 2024/04/07 22:26:27 repository/repository.go:267 repository.(*Repository).LoadBlob 1 load tree with id 15861b4443b66ab2c51c38d26dc7e79abc0c89fe7a83184340946ebac54d6d3b (buf len 0, cap 0) 2024/04/07 22:26:27 repository/repository.go:281 repository.(*Repository).LoadBlob 1 blob tree/15861b4443b66ab2c51c38d26dc7e79abc0c89fe7a83184340946ebac54d6d3b found: 2024/04/07 22:26:27 backend/readerat.go:31 backend.ReadAt 1 ReadAt() at 0, len 274 2024/04/07 22:26:27 cache/file.go:38 cache.(*Cache).load 1 Load(, 274, 0) from cache 2024/04/07 22:26:27 backend/readerat.go:42 backend.ReadAt 1 ReadAt() ReadFull returned 274 bytes 2024/04/07 22:26:27 restorer/restorer.go:96 restorer.(*Restorer).traverseTree 1 SelectFilter returned true true for "/readonly.txt" 2024/04/07 22:26:27 restorer/restorer.go:253 restorer.(*Restorer).RestoreTo.func2 1 first pass, visitNode: mkdir "/readonly.txt", leaveDir on second pass should restore metadata 2024/04/07 22:26:27 repository/repository.go:990 repository.streamPackPart 73 streaming pack 2ae200578b615584d7496f03166e37834bc4ea30796e3655a1597cd4df0d6f45 (0 to 48 bytes), blobs: 1 2024/04/07 22:26:27 cache/file.go:38 cache.(*Cache).load 73 Load(, 48, 0) from cache 2024/04/07 22:26:27 restorer/filerestorer.go:190 restorer.(*fileRestorer).restoreFiles.func3 75 Scheduled download pack 2ae20057 2024/04/07 22:26:27 cache/backend.go:172 cache.(*Backend).Load 73 error loading from cache: open ${REDACTED} 2024/04/07 22:26:27 cache/backend.go:176 cache.(*Backend).Load 73 Load(, 48, 0): delegating to backend 2024/04/07 22:26:27 logger/log.go:45 logger.(*Backend).Load 73 Load(, length 48, offset 0) 2024/04/07 22:26:27 sema/semaphore.go:27 sema.semaphore.GetToken 73 acquired token 2024/04/07 22:26:27 repository/repository.go:1028 repository.streamPackPart.func1 73 process blob , skipped 0, 2024/04/07 22:26:27 logger/log.go:47 logger.(*Backend).Load 73 load err 2024/04/07 22:26:27 restorer/restorer.go:304 restorer.(*Restorer).RestoreTo 1 second pass for "/tmp/foo1" 2024/04/07 22:26:27 restorer/restorer.go:56 restorer.(*Restorer).traverseTree 1 /tmp/foo1 / 15861b4443b66ab2c51c38d26dc7e79abc0c89fe7a83184340946ebac54d6d3b 2024/04/07 22:26:27 restic/tree.go:113 restic.LoadTree 1 load tree 15861b4443b66ab2c51c38d26dc7e79abc0c89fe7a83184340946ebac54d6d3b 2024/04/07 22:26:27 repository/repository.go:267 repository.(*Repository).LoadBlob 1 load tree with id 15861b4443b66ab2c51c38d26dc7e79abc0c89fe7a83184340946ebac54d6d3b (buf len 0, cap 0) 2024/04/07 22:26:27 repository/repository.go:281 repository.(*Repository).LoadBlob 1 blob tree/15861b4443b66ab2c51c38d26dc7e79abc0c89fe7a83184340946ebac54d6d3b found: 2024/04/07 22:26:27 backend/readerat.go:31 backend.ReadAt 1 ReadAt() at 0, len 274 2024/04/07 22:26:27 cache/file.go:38 cache.(*Cache).load 1 Load(, 274, 0) from cache 2024/04/07 22:26:27 backend/readerat.go:42 backend.ReadAt 1 ReadAt() ReadFull returned 274 bytes 2024/04/07 22:26:27 restorer/restorer.go:96 restorer.(*Restorer).traverseTree 1 SelectFilter returned true true for "/readonly.txt" 2024/04/07 22:26:27 restorer/restorer.go:309 restorer.(*Restorer).RestoreTo.func3 1 second pass, visitNode: restore node "/readonly.txt" 2024/04/07 22:26:27 restorer/restorer.go:180 restorer.(*Restorer).restoreNodeMetadataTo 1 restoreNodeMetadata readonly.txt /tmp/foo1/readonly.txt /readonly.txt 2024/04/07 22:26:27 restic/lock.go:222 main.monitorLockRefresh 68 terminate expiry monitoring 2024/04/07 22:26:27 restic/lock.go:158 main.refreshLocks 67 terminate 2024/04/07 22:26:27 restic/lock.go:146 main.refreshLocks.func1 67 unlocking repository with lock PID 111382 on ${REDACTED} (UID 1000, GID 100) lock was created at 2024-04-07 22:26:27 (205.98731ms ago) storage ID ec80ff39 2024/04/07 22:26:27 cache/backend.go:37 cache.(*Backend).Remove 67 cache Remove() 2024/04/07 22:26:27 logger/log.go:38 logger.(*Backend).Remove 67 Remove() 2024/04/07 22:26:27 logger/log.go:40 logger.(*Backend).Remove 67 remove err 2024/04/07 22:26:27 restic/lock.go:300 main.unlockAll 1 unlocking 0 locks 2024/04/07 22:26:27 restic/cleanup.go:87 main.Exit 1 exiting with status code 1