{"action":"created","issue":{"url":"https://api.github.com/repos/gilbertchen/duplicacy/issues/205","repository_url":"https://api.github.com/repos/gilbertchen/duplicacy","labels_url":"https://api.github.com/repos/gilbertchen/duplicacy/issues/205/labels{/name}","comments_url":"https://api.github.com/repos/gilbertchen/duplicacy/issues/205/comments","events_url":"https://api.github.com/repos/gilbertchen/duplicacy/issues/205/events","html_url":"https://github.com/gilbertchen/duplicacy/issues/205","id":259298426,"node_id":"MDU6SXNzdWUyNTkyOTg0MjY=","number":205,"title":"Restore should not come to a full stop when a corrupt chunk is encountered.","user":{"login":"macdanny","id":12475584,"node_id":"MDQ6VXNlcjEyNDc1NTg0","avatar_url":"https://avatars3.githubusercontent.com/u/12475584?v=4","gravatar_id":"","url":"https://api.github.com/users/macdanny","html_url":"https://github.com/macdanny","followers_url":"https://api.github.com/users/macdanny/followers","following_url":"https://api.github.com/users/macdanny/following{/other_user}","gists_url":"https://api.github.com/users/macdanny/gists{/gist_id}","starred_url":"https://api.github.com/users/macdanny/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/macdanny/subscriptions","organizations_url":"https://api.github.com/users/macdanny/orgs","repos_url":"https://api.github.com/users/macdanny/repos","events_url":"https://api.github.com/users/macdanny/events{/privacy}","received_events_url":"https://api.github.com/users/macdanny/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":3,"created_at":"2017-09-20T20:53:04Z","updated_at":"2018-06-18T16:41:52Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"This is partly a continuation of the \"Duplicacy keeps stalling\" issue on the duplicacy web site. I am not allowed to add more comments there because I have \"reached my post limit\".\r\n\r\n---\r\n\r\nI switched to the s3c provider, cranked up the threads to 128, and let it run. It got about 600 chunks in and then crashed:\r\n\r\n```\r\n2017-09-20 12:50:45.539 ERROR UPLOAD_CHUNK Failed to decrypt the chunk ca9c51caa3e5cae3e48d72b65cd80618b7e27537b51732c54e884efcce9adc88: The storage doesn't seem to be encrypted\r\ngoroutine 134 [running]:\r\nruntime/debug.Stack(0x0, 0x0, 0xc42a62d6b8)\r\n        /usr/local/go/src/runtime/debug/stack.go:24 +0x79\r\nruntime/debug.PrintStack()\r\n        /usr/local/go/src/runtime/debug/stack.go:16 +0x22\r\ngithub.com/gilbertchen/duplicacy/src.CatchLogException()\r\n        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_log.go:177 +0x13d\r\npanic(0xc6d3a0, 0xc42834a900)\r\n        /usr/local/go/src/runtime/panic.go:489 +0x2cf\r\ngithub.com/gilbertchen/duplicacy/src.logf(0x2, 0xd1868f, 0xc, 0xd2c6f6, 0x22, 0xc42a62dd40, 0x2, 0x2)\r\n        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_log.go:160 +0x1bc\r\ngithub.com/gilbertchen/duplicacy/src.LOG_ERROR(0xd1868f, 0xc, 0xd2c6f6, 0x22, 0xc42a62dd40, 0x2, 0x2)\r\n        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_log.go:98 +0x73\r\ngithub.com/gilbertchen/duplicacy/src.(*ChunkDownloader).Download(0xc42876cf00, 0x47, 0x0, 0x27d, 0xc42abb77e0, 0x20, 0x331d30, 0x1, 0xc4265e4e01)\r\n        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_chunkdownloader.go:336 +0x547\r\ngithub.com/gilbertchen/duplicacy/src.CreateChunkDownloader.func1(0xc42876cf00, 0x47)\r\n        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_chunkdownloader.go:81 +0x161\r\ncreated by github.com/gilbertchen/duplicacy/src.CreateChunkDownloader\r\n        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_chunkdownloader.go:86 +0x23f\r\n```\r\n\r\nThis is an interesting one because it had already successfully restored over 77,000 files at this point. Maybe the issue results from the large number of threads I was using.\r\n\r\nI also saw a bunch of messages like this.\r\n\r\n```\r\n2017-09-20 12:50:25.182 WARN CONFIG_CHUNK 190 chunks have been allocated\r\n```\r\n\r\nI suppose these are not important? It has to hold the chunks in sequence and they may arrive out of order if multiple threads are in use. I don't know why it's holding > 128 chunks though.\r\n\r\nI switched back to s3 and started over with 16 threads. I get the same error, on the same chunk.\r\n\r\nI think this is a sign of an undetected error when creating the initial backup to Wasabi with duplicacy.  This is why:\r\n\r\n1. I backed up directly to Wasabi.\r\n2. I created a new local storage using duplicacy add -copy.\r\n3. I copied the config file and the snapshot files from Wasabi to the local storage thus created, so the same encryption keys would be used.\r\n4. I backed up directly into my new local storage.  Since it used the same parameters including the same encryption keys, it created the very same chunks.\r\n5. Against the local storage, I ran duplicacy check and (manually) copied missing chunks from Wasabi to the local storage until duplicacy check completed successfully.\r\n6. Against the local storage, I ran duplicacy check with the -files option.  It took days but it completed successfully with no issues.  I am therefore absolutely confident that the local storage is OK.\r\n7. As above ... I ran duplicacy restore to restore from Wasabi into a new repository.  It failed.\r\n8. I downloaded the failing chunk from Wasabi and compared it to the chunk from the local storage.  They are different.  They are exactly the same size, but their contents are completely different.\r\n9. I uploaded the chunk from the local storage into Wasabi.\r\n10. I am now running the same restore that failed. It's still going but it is past the chunk that it was getting stuck on.\r\n\r\nThe chunk on Wasabi was wrong. This could only have happened during the backup.  Or after, I guess, if you think it's credible that bit rot did this on the Wasabi end.\r\n\r\nIt could be a problem with duplicacy or a library it depends on, or a problem with Wasabi.\r\n\r\nThe working chunk starts with \"duplicacy\\x00\". The corrupt chunk does not. Adjacent chunks on Wasabi also start with \"duplicacy\\x00\". So far this is the only one that doesn't.\r\n\r\n> That chunk doesn't have a valid encryption header. Can you download it from wasabi.com and check the first 10 bytes of the file? Do you have a local copy of that chunk (if you copied from local storage to wasabi)?\r\n\r\nYes, I have both chunks. It's how I know they were different. The bad chunk starts with\r\n\r\n46 ac 59 b1 59 f9 17 83 08 b8\r\n\r\nIs there a way to tell if it's a valid but unencrypted chunk? It's definitely not encrypted because there are large swaths of repeating sequences which you shouldn't see in ciphertext.\r\n\r\n---\r\n\r\nI hit this now.\r\n\r\n<pre>\r\n2017-09-20 14:14:58.785 INFO DOWNLOAD_PROGRESS Downloaded chunk 1459 size 1126823, 3.67MB/s 1 day 14:43:08 1.3%                goroutine 25 [running]:\r\nruntime/debug.Stack(0x0, 0x0, 0xc42abeb6b8)\r\n        /home/flowers/.local/app/go/src/runtime/debug/stack.go:24 +0x79\r\nruntime/debug.PrintStack()\r\n        /home/flowers/.local/app/go/src/runtime/debug/stack.go:16 +0x22\r\ngithub.com/gilbertchen/duplicacy/src.CatchLogException()\r\n        /home/flowers/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_log.go:177 +0x13d\r\npanic(0xc88fc0, 0xc422ac6540)\r\n        /home/flowers/.local/app/go/src/runtime/panic.go:489 +0x2cf\r\ngithub.com/gilbertchen/duplicacy/src.logf(0x2, 0xd37220, 0xc, 0xd4b59b, 0x22, 0xc42abebd40, 0x2, 0x2)                                  /home/flowers/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_log.go:160 +0x1bc\r\ngithub.com/gilbertchen/duplicacy/src.LOG_ERROR(0xd37220, 0xc, 0xd4b59b, 0x22, 0xc42abebd40, 0x2, 0x2)                                  /home/flowers/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_log.go:98 +0x73\r\ngithub.com/gilbertchen/duplicacy/src.(*ChunkDownloader).Download(0xc428712320, 0x4, 0x0, 0x5aa, 0xc4239474c0, 0x20, 0x7eb14b, 0x1, 0x1)\r\n        /home/flowers/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_chunkdownloader.go:336 +0x547\r\ngithub.com/gilbertchen/duplicacy/src.CreateChunkDownloader.func1(0xc428712320, 0x4)                                                    /home/flowers/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_chunkdownloader.go:81 +0x161\r\ncreated by github.com/gilbertchen/duplicacy/src.CreateChunkDownloader                                                                  /home/flowers/go/src/github.com/gilbertchen/duplicacy/src/duplicacy_chunkdownloader.go:86 +0x23f\r\n2017-09-20 14:15:00.139 ERROR UPLOAD_CHUNK Failed to decrypt the chunk 7153a420a3c53d4844b8ab2f3f82b5af7e0e4709af3916d2dae1e4e99459634c: cipher: message authentication failed\r\n</pre>\r\n\r\nThis one does start with \"duplicacy\" but it couldn't be decrypted. This is making me think I must have messed up. I definitely did not manually upload any chunks to Wasabi, except as described above. But when I was trying to figure out how duplicacy works, I might have re-created the repository a few times on my machine and not wiped out what had already been uploaded to Wasabi. I think I thought it wouldn't matter because I thought the chunk hashes depended not only on the chunk contents but on the encryption key as well.\r\n\r\nRegardless of how it happens though, it is not out of the question that a chunk could become corrupt due to bit rot. A single corrupt chunk should not prevent the restoration of all subsequent files that reside wholly inside valid chunks. If the corrupt chunk is encountered early it could make virtually the entire backup inaccessible.\r\n\r\nDuplicacy should skip the files that are stored in the corrupt chunk and resume restoring files when it gets back into valid chunks. It should log the names of the files that could not be restored.\r\n\r\nEDIT: I copied information for context from the duplicacy issue into here (between the horizontal rules)."},"comment":{"url":"https://api.github.com/repos/gilbertchen/duplicacy/issues/comments/398118222","html_url":"https://github.com/gilbertchen/duplicacy/issues/205#issuecomment-398118222","issue_url":"https://api.github.com/repos/gilbertchen/duplicacy/issues/205","id":398118222,"node_id":"MDEyOklzc3VlQ29tbWVudDM5ODExODIyMg==","user":{"login":"skidvd","id":5832513,"node_id":"MDQ6VXNlcjU4MzI1MTM=","avatar_url":"https://avatars3.githubusercontent.com/u/5832513?v=4","gravatar_id":"","url":"https://api.github.com/users/skidvd","html_url":"https://github.com/skidvd","followers_url":"https://api.github.com/users/skidvd/followers","following_url":"https://api.github.com/users/skidvd/following{/other_user}","gists_url":"https://api.github.com/users/skidvd/gists{/gist_id}","starred_url":"https://api.github.com/users/skidvd/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/skidvd/subscriptions","organizations_url":"https://api.github.com/users/skidvd/orgs","repos_url":"https://api.github.com/users/skidvd/repos","events_url":"https://api.github.com/users/skidvd/events{/privacy}","received_events_url":"https://api.github.com/users/skidvd/received_events","type":"User","site_admin":false},"created_at":"2018-06-18T16:41:52Z","updated_at":"2018-06-18T16:41:52Z","author_association":"NONE","body":"I am curious if there has been any progress/plans with respect to the use of the MD5 checksum for ensuring the integrity of the source to storage exchange?"}}
{"actor":{"display_login":"skidvd"}}