Backups have stopped, no emails reporting it and missing chunks

Please describe what you are doing to trigger the bug:

Windows Server 2016, ran GUI as admin, runs as a service on schedule with email alerts.

I’ve used it for a couple months and it worked perfectly at the beginning.

Currently it does not perform the backups on schedule and when I check the server I find this error

I get no email about it and I do not know if backups are being really performed of not.

So… A few things to be safe:

  • No, I have not manually touched the B2 files in any way and its retention policy is set as recommended

  • I have the default prune policy

  • I got all the logs uploaded to google drive, I’ll be more than fine to share them… I just don’t know if doing it publicly would be a good idea

Can you check the lifecycle rule setting on your B2 bucket? It should be set to Keep all versions of the file which is the default one. Other settings are knows to cause the exact same issue.

If this setting is correct, please submit a ticket on duplicacy.com and share the links to your log files (including both backup and prune logs found under .duplicacy/logs).

Can I ask why that matters? Shouldn’t all the chunks be uploaded with a unique hash-name and therefore all versions of any one chunk/file would be identical? Most file systems don’t allow versioning…why is B2 different?

2018-10-26_12-52-17

I thought this bug report is already a ticket

Here’s the link for the logs Google Drive Folder

I edited your post to remove the link to the logs.

One more question, is this the only machine that backs up to that bucket?

Yes, positive, affirmative, correct the only one (Post must be at least 20 characters)

The backup on Oct 20 was the first one to have the problem:

2018-10-20 16:04:30.026 INFO CHUNK_DELETE The chunk d2502f9c0d9617571cc648ec036d33829a01feee2df2cec7eac45c66adea5d36 has been permanently removed
2018-10-20 16:04:30.076 INFO CHUNK_DELETE The chunk b1fc3827cd658c69a82363250e4d8c27e7771769a37d6901664d12a619b07ce0 has been pe2018-10-20 16:11:48.841 ERROR CHUNK_FIND Chunk 7b1a247f067955e6b61fbc45fb8c11865ec08fbfc628803ab5f55d0b0f28809c does not exist in the storage
[16:11:48] \\Omniconas1\pc_backups Prune operation returned an error:
ERROR Chunk 7b1a247f067955e6b61fbc45fb8c11865ec08fbfc628803ab5f55d0b0f28809c does not exist in the storage

 16:04:30.179 INFO CHUNK_DELETE The chunk 9fba2a60a9e0d4807a90c4a2bdf9fb8c780ca6095bb634fd45b6bb9da09e3b22 has been permanently removed
2018-10-20 16:04:30.226 INFO CHUNK_DELETE The chunk cf7cc95e9d5a2f97f0570c95cfbc8058019afeb273d1129212ab899c21b8107a has been permanently removed
2018-10-20 16:04:30.247 INFO CHUNK_DELETE The chunk 5b5b5dae917841c765f7507d010eca82b6b1a87f62ef68f02f585f4cdb1c8c64 has been permanently removed
2018-10-20 16:04:30.297 INFO CHUNK_DELETE The chunk 8cdf0b109ebfd3682131588422e747a5699b7f8fb02e6251f91b38c7a54a2b84 has been permanently removed
2018-10-20 16:04:30.336 INFO CHUNK_DELETE The chunk dd7f4ec7f75b7e346cc1f150a526efec9e9fcaf7cc081cb4206947ff907782f5 has been permanently removed
2018-10-20 16:04:30.374 INFO CHUNK_DELETE The chunk c41aea138f684b77a9226b2303183d6c7016d69efdf5f06d5f665e226f491951 has been permanently removed
2018-10-20 16:04:30.411 INFO CHUNK_DELETE The chunk 302e97de6df273e02f179ec327e123be983f81a9260beb6bfebeb80313533abd has been permanently removed
2018-10-20 16:04:30.445 INFO SNAPSHOT_DELETE Deleting snapshot OMNICO_PC_BACKUPS at revision 36
2018-10-20 16:04:30.452 INFO CHUNK_DELETE The chunk 747c0d729c316edd019c6c94b7d5674d05c45c7fe9f4ea2d616c639dbe411fa7 has been permanently removed
2018-10-20 16:04:30.499 INFO CHUNK_DELETE The chunk c14689cbb9307b7286dc3c45dab247c49999d8ea15e789489dc5d728622db48e has been permanently removed
2018-10-20 16:04:30.542 INFO CHUNK_DELETE The chunk 3906b039868a38d024b93f9342617e13b1939113f6fe9924904bc5a84e05510a has been permanently removed
2018-10-20 16:09:46.202 ERROR CHUNK_FIND Chunk dd88c4d954bc24e7c9d222bc287c6a5c01b33a82509ff1c5a0b4b835ed89e0d7 does not exist in the storage
[16:09:46] \\Omniconas1\pc_backups Prune operation returned an error:
ERROR Chunk dd88c4d954bc24e7c9d222bc287c6a5c01b33a82509ff1c5a0b4b835ed89e0d7 does not exist in the storage

From the log it looks like two prune commands were running at the same time. This could be a bug in the GUI, but any chance you may have both the GUI and the service running at the same time?

The logs indicated that backups after Oct 20 were still ok; it was the prune command that always failed.

Also, it seems that some chunks reported to not exist were just turned into fossils, not permanently removed. So you may be able to fix it by running this command in a DOS window:

cd \\Omniconas1\pc_backups
"c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe" check -resurrect -all

If this command still reports missing chunks, it may be because the prune command may have permanently removed some fossils before deleting the corresponding snapshots (due to those errors). If this is the case, you’ll need to manually delete the affected snapshot files on the B2 web page.

This page should have more details on how you can fix the issue.

First of all: Thanks :ok_hand:t3:

I think I left the GUI open and then disconnected from the server…

No idea that would get 2 working and overlapping instances fighting over the prune command.

I’ll run the command and report back the results.

Here you go: Command results

Also… Manually ran a backup and got this:

I’ve added the new logs to the previously shared google drive folder.

You can manually remove the file named OMNICO_PC_BACKUPS/36 from the storage (through the b2 web site). It is likely that this revision file was selected to be removed by one of the failed prune operations, so it should be safe to delete this file.

After that, run the check command again and for each revision reported to have missing chunks, remove the corresponding revision file. Once the check command reports no missing chunks, you can run this command to clean up the storage:

"c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe" prune -exclusive -exhaustive

This command will list all chunks on the storage (the -exhaustive option), identify unreferenced chunks and remove them immediately (the -exclusive option). Do not run any backup before this prune command finishes.

Deleted snapshots/OMNICO_PC_BACKUPS/36
Ran
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -all
Said:
Some chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 37 are missing
Deleted snapshots/OMNICO_PC_BACKUPS/37

Ran
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -all
Said:
Some chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 39 are missing
Deleted snapshots/OMNICO_PC_BACKUPS/39

Same with 40, 41, 42, 43, 44, 46, 47, 48, 49, 50, 51, 53, 54, 55, 56, 57, 58, 60, 61, 62…

This is getting silly…

How can I tell the command to find ALL of the missing chunks without it stopping every time?

Something like:

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -allRegarlessOfMissingChunks

Perhaps:

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 48 … 78 ?

I tried:

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 54 + 55 + 56 + 57 + 58 59 + 60 + 61 + 62 + 63 + 64 + 65 + 66 + 67 + 68 + 69 + 70 + 71 + 72 + 73 + 74 + 75 + 76 + 77 + 78

and…

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 54+

and…

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 54 +

and…

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 54 +55 +56 +57 +58 59 +60 +61 +62 +63 +64 +65 +66 +67 +68 +69 +70 +71 +72 +73 +74 +75 +76 +77 +78

and…

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 54+55+56+57+5859+60+61+62+63+64+65+66+67+68+69+70+71+72+73+74+75+76+77+78

Does not work…

UPDATE: (After running #54 through #65 manually… Going half insane… Pondering upon my life choices and thinking about changing career paths and finally googling my way out and realizing my subpar CLI skills) Using excel I created a series of numbers… It’s nasty and messy… But gets the job done…

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 66
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 67
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 68
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 69
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 70
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 71
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 72
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 73
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 74
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 75
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 76
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 77
&
“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -r 78

UPDATE 2:
Eventually:

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” check -all
Storage set to b2://DuplicacyOMNICODATA
Listing all chunks
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 1 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 4 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 12 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 18 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 24 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 31 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 38 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 45 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 52 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 59 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 63 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 64 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 65 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 66 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 67 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 68 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 69 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 70 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 71 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 72 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 73 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 74 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 75 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 76 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 77 exist
All chunks referenced by snapshot OMNICO_PC_BACKUPS at revision 78 exist

Then

Ran:

“c:\Program Files (x86)\Duplicacy\duplicacy_win_x64_2.1.1.exe” prune -exclusive -exhaustive

It is erasing an obscene amount of chunks, I’ll update with the backup operation results :slight_smile:

1 Like

Backup seemed to work, it send no email since it was ran manually and not on schedule (Hint hint)

Logs have been added to previously shared folder for review.

Also, a question, I have the program running as a service, would letting it run on the tray cause any issues?

Yes.

If you open the Duplicacy GUI and go to the Logs tab, it says the service is paused.

Even when you close the window and keep it running in the tray, check the activity in services.msc - you’ll find it’s still paused. You have to right-click the tray icon and Quit for the service to resume.

This is why I don’t currently use the service, it’s something I hope and believe will be fixed in GUI 2.0.

So… Due to all these things I just gave up… I wiped my Backblaze container, deleted the duplicacy folder on the repository and started from scratch.

And then I found 2 other issues and to both I propose solutions: (I do this with the best intentions, not criticizing, I know enough programming to know that it is hard work, respect :clap:t4:)

1.
Even though it was the 1st backup, the logs kept checking whether or not the chunk already existed before uploading it,

2018-12-01 23:35:42.858 DEBUG BACKBLAZE_CALL URL request ‘HEAD https://f002.backblazeb2.com/file/ContainerName/chunks/ChunkName’ returned status code 404

2018-12-01 23:35:42.858 DEBUG BACKBLAZE_LIST b2_download_file_by_name did not return headers

2018-12-01 23:35:45.937 DEBUG CHUNK_UPLOAD Chunk ChunkName has been uploaded

2018-12-01 23:35:45.937 INFO UPLOAD_PROGRESS Uploaded chunk ChunkNumber size 5968306, 3.03MB/s 6 days 07:44:32 34.2%

Which I guess it’s fine… But it definitely looked like was wasting precious time…

Maybe add an option that either: Wipes the container before beginning (Maybe add a warning like "I know what I’m doing, wipe before beginning, this is the initial backup) or just asks: Is this an initial backup? Is the container free of any chunks or conflicting files? Do you know what you’re doing?..

After more than a week, (On a 50/50 mbps link) the backup finally finished.

2.

However, I’m still getting no email notifications even though the logs say the email was sent correctly…

04:51:41.000 CURL: 235 Authentication Successful
04:51:41.000 CURL: MAIL FROM:<source@email>
04:51:41.000 CURL: 250 Sender <source@email> OK
04:51:41.000 CURL: RCPT TO:<destination@1>
04:51:41.000 CURL: 250 Recipient <destination@1> OK
04:51:41.000 CURL: RCPT TO:<destination@2>
04:51:42.000 CURL: 250 Recipient <destination@2> OK
04:51:42.000 CURL: DATA
04:51:42.000 CURL: 354 Ok Send data ending with .
04:51:42.000 CURL: From: source@email To: destination@1;destination@2; Subject: Deduping Status Log file: \Repository\.duplicacy\logs\backup-log-20181204-163300 2018-12-04 16:33:00.929 INFO STORAGE_SET Storage set to b2://ContainerName 2018-12-04 16:33:00.932 DEBUG PASSWORD_ENV_VAR Reading the environment variable DUPLICACY_GUI1_B2_ID 2018-12-04 16:33:00.948 DEBUG PASSWORD_KEYCHAIN Reading b2_id from keychain/keyring 2018-12-04 16:33:00.948 DEBUG PASSWORD_ENV_VAR Read

My theory is that it is trying to attach the log file, the log file exceeds the 25 MB attachment limit of my email service and never gets sent, I totally can understand such limitation, however, I really need email notifications.

If my theory is correct, I already have a 3 solutions: (I like all of them… Maybe all of them are possible :grinning:)

  1. Create an option that: if attachment file is bigger than (Email’s attachment limit), split the log into chunks (Maybe a ZIP) and sent it that way, you would end up with some messages, like:

“Duplicacy backup successful (1/3)”
“Duplicacy backup successful (2/3)”
“Duplicacy backup successful (3/3)”

  1. Create an option that: if attachment file is bigger than (Email’s attachment limit), skip log file attachment, messages would be like:

“Duplicacy backup successful (Log file size exceeds server limit, check source for details)”

  1. (The logical evolution of #2) Create an option that: if attachment file is bigger than (Email’s attachment limit), upload log to a google drive (Or dropbox or whatever) folder:

“Duplicacy backup successful (Log file size exceeds server limit, uploaded to specified cloud folder)”

Is my theory correct? or am I doing something wrong, in any case, how can I resolve it?

  1. That is an option I’ll consider, but how many threads did you use? It looks like you didn’t saturate your upload link so maybe you could have used more threads.

  2. This will be fixed in the new web-based GUI, for which there is an option to limit the email size.