Hi Jim, please confirm it was the initial backup. Could you try to run the plan one more time to see the same stats parameters - what counts are?

Hi Julia, thanks - yes it was the initial run. When I went to run it again I found the diagnostic log. It has a lot of errors, such as

2018-04-12 22:09:33,084 [CL] [10] ERROR - Command::Run failed:
Copy; Source:D:\media\sony-dump\2016Feb-March\DSC07000.JPG; Destination:/backup-work7/CBB_WORK7/D:/media/sony-dump/2016Feb-March/
System.Security.Cryptography.CryptographicException: Unknown error "-1073741823".
at System.Security.Cryptography.BCryptNative.OpenAlgorithm(String algorithm, String implementation)
at System.Security.Cryptography.BCryptAlgorithmHandleCache.GetCachedAlgorithmHandle(String algorithm, String implementation)
at System.Security.Cryptography.BCryptHashAlgorithm..ctor(CngAlgorithm algorithm, String implementation)
at System.Security.Cryptography.SHA256Cng..ctor()
at uO.a()
at xQ.a(Stream )
at aFq.JZ(uu )
at uz.A(uu )
at uz.B(uu )
at uz.b(uu )
at uz.C(uu )
at Va.jd(uu )
at aFq.A(String , String , air , uB , Stream , Boolean , Xs )
at aip.Mx(String , String , air , uB , Fn`1 , Boolean , Int64 , Xs )
at afw.lw(zg , Xs )
at zL.A(Object , zK )
at zp.A(zK )
at zp.kT(ICancelable )
at zL.a(Int64 , Xs )
at ajX.A(Stream , Int64 , Int64 , Xs , EncryptionSettings , Boolean , Int64 , adI )
at ajX.hr(Stream , yx , adI )
at Zo.iB(Zf , String , yx )
at yz.eG()
at agO.eG()
at yy.Kq()


2018-04-12 22:09:33,224 [CL] [9] ERROR - Generating chunks failed
System.Security.Cryptography.CryptographicException
Unknown error "-1073741823".
at System.Security.Cryptography.BCryptNative.OpenAlgorithm(String algorithm, String implementation)
at System.Security.Cryptography.BCryptAlgorithmHandleCache.GetCachedAlgorithmHandle(String algorithm, String implementation)
at System.Security.Cryptography.BCryptHashAlgorithm..ctor(CngAlgorithm algorithm, String implementation)
at System.Security.Cryptography.SHA256Cng..ctor()
at uO.a()



2018-04-12 22:09:33,240 [PL] [9] ERROR - Error occurred during backup Upload operation. Cloud path: backup-work7/CBB_WORK7/D:/media/sony-dump/2016Feb-March/DSC07001.JPG. IsSimple: True. Modified date: 18/03/2016 20:01:24. Size: 4.0 MB (4201851)
System.Security.Cryptography.CryptographicException
Unknown error "-1073741823".
at System.Security.Cryptography.BCryptNative.OpenAlgorithm(String algorithm, String implementation)
at System.Security.Cryptography.BCryptAlgorithmHandleCache.GetCachedAlgorithmHandle(String algorithm, String implementation)
at System.Security.Cryptography.BCryptHashAlgorithm..ctor(CngAlgorithm algorithm, String implementation)
at System.Security.Cryptography.SHA256Cng..ctor()
at uO.a()
at xQ.a(Stream )
at aFq.JZ(uu )
at uz.A(uu )
at uz.B(uu )
at uz.b(uu )
at uz.C(uu )
at Va.jd(uu )
at aFq.A(String , String , air , uB , Stream , Boolean , Xs )
at aip.Mx(String , String , air , uB , Fn`1 , Boolean , Int64 , Xs )
at afw.lw(zg , Xs )
at zL.A(Object , zK )
at zp.A(zK )
at zp.kT(ICancelable )
at zL.a(Int64 , Xs )
at ajX.A(Stream , Int64 , Int64 , Xs , EncryptionSettings , Boolean , Int64 , adI )
at ajX.hr(Stream , yx , adI )
at Zo.iB(Zf , String , yx )
at yz.eG()
at agO.eG()
at yy.Kq()
at aaG.D()

All log files are attached.

How do I make it backup again? At the moment it has "Instant back starts in X seconds" it gets to 0 seconds but timer just starts counting down again.

Thanks for the details! It seems that you use a real-time backup - this is why you see the "Instant back starts in X seconds" note. The real-time plan is always running, it checks for new/modified files every 60 sec. Actually, I would recommend to switch from real-time to a regular schedule. Scheduled backup allows you to manage the start/stop time and get an immediate notification on completion. How often do you have updates on the selected folder?

Meanwhile, I am going to check your logs to learn more about the case.

As I can see that the "Unknown error "-1073741823 occured in the mid of April last time. Further errors are connection failures that were retried and no failures related to files. Let's switch real-time to a regular schedule and see how it runs. Please keep me informed. Thanks!

Yes I should have said the mid April date was the first and only time it ran, I just didn't get around to figuring this out 'til now.

I've switched it to scheduled and tried to run it, but it stops after 23 seconds. The files have not changed since last backup and don't change often. Please see screenshot.

2018-05-14 09:43:33,700 [SERV] [31] WARN - ForceInterrupt (by user) event occurred
2018-05-14 09:43:34,019 [SERV] [31] WARN - Interrupt backup event occurred. Reason: Manual
2018-05-14 09:43:34,599 [SERV] [31] WARN - Thread engine interrupted
2018-05-14 09:43:34,681 [PL] [31] ERROR - Copy creator interrupted
2018-05-14 09:43:34,715 [SERV] [31] WARN - Creator queue interrupted
2018-05-14 09:43:35,541 [SERV] [1] WARN - Engine was interrupted manually
2018-05-14 09:43:36,177 [SERV] [1] NOTICE - Elapsed time: 12:25:40. Max memory usage: 59 MB. Processor time: 00:00:12. DB connection: 356 DB query: 456 Status report: 9108
2018-05-14 09:43:36,250 [SERV] [1] NOTICE - CloudBerry Backup - Freeware. Version: 5.8.6.27
2018-05-14 09:43:36,366 [SERV] [1] NOTICE - Plan status: Interrupted. Elapsed time: 12:25:40.1602641. Version: 5.8.6.27
2018-05-14 09:43:36,401 [SERV] [1] NOTICE - Scanned: 9340(93.6 GB). Uploaded: 3(11 KB). Deleted: 0. Failed: 0
2018-05-14 09:43:36,432 [SERV] [1] NOTICE - Items added for backup: 3. Bytes sent: 12029(11 KB)
2018-05-14 09:45:33,065 [SERV] [1] NOTICE - **********************************************************************************************************
2018-05-14 09:45:33,137 [SERV] [1] NOTICE - CloudBerry Backup - Freeware Engine Started. Version: 5.8.6.27
2018-05-14 09:45:33,172 [SERV] [1] NOTICE - Plan 7a6a9192-1b65-4e4c-98d4-bd2dac4caec5 'Backup plan on 2018-04-11 2:38:01 PM' (Plan). Force full mode :False
2018-05-14 09:45:34,069 [Base] [1] WARN - Unknown .net version: 461308
2018-05-14 09:45:34,136 [Base] [1] WARN - Unknown .net version: 461308
2018-05-14 09:45:58,188 [PL] [1] NOTICE - Creating purge queue started. Purge conditions: version count: 3
2018-05-14 09:45:58,282 [PL] [1] NOTICE - Purge version search time: 00:00:00. Files checked for this plan: 0. Files for purge found: 0
2018-05-14 09:45:58,342 [PL] [1] NOTICE - Purge locally deleted search time: 00:00:00. Locally deleted files checked: 0. Files for purge found: 0
2018-05-14 09:45:58,766 [SERV] [1] NOTICE - Elapsed time: 00:00:24. Max memory usage: 63 MB. Processor time: 00:00:07. DB connection: 196 DB query: 288 Status report: 28
2018-05-14 09:45:58,815 [SERV] [1] NOTICE - CloudBerry Backup - Freeware. Version: 5.8.6.27
2018-05-14 09:46:02,807 [SERV] [1] NOTICE - Plan status: Success. Elapsed time: 00:00:26.9204470. Version: 5.8.6.27
2018-05-14 09:46:02,855 [SERV] [1] NOTICE - Scanned: 9340(93.6 GB). Uploaded: 3(11 KB). Deleted: 0. Failed: 0
2018-05-14 09:46:02,887 [SERV] [1] NOTICE - Items added for backup: 3. Bytes sent: 12026(11 KB)
2018-05-14 09:46:51,993 [SERV] [1] NOTICE - **********************************************************************************************************
2018-05-14 09:46:52,058 [SERV] [1] NOTICE - CloudBerry Backup - Freeware Engine Started. Version: 5.8.6.27
2018-05-14 09:46:52,093 [SERV] [1] NOTICE - Plan 7a6a9192-1b65-4e4c-98d4-bd2dac4caec5 'Backup plan on 2018-04-11 2:38:01 PM' (Plan). Force full mode :False
2018-05-14 09:46:52,274 [Base] [1] WARN - Unknown .net version: 461308
2018-05-14 09:46:52,308 [Base] [1] WARN - Unknown .net version: 461308
2018-05-14 09:47:04,589 [PL] [1] NOTICE - Creating purge queue started. Purge conditions: version count: 3
2018-05-14 09:47:04,698 [PL] [1] NOTICE - Purge version search time: 00:00:00. Files checked for this plan: 0. Files for purge found: 0
2018-05-14 09:47:04,751 [PL] [1] NOTICE - Purge locally deleted search time: 00:00:00. Locally deleted files checked: 0. Files for purge found: 0
2018-05-14 09:47:05,083 [SERV] [1] NOTICE - Elapsed time: 00:00:12. Max memory usage: 59 MB. Processor time: 00:00:07. DB connection: 192 DB query: 279 Status report: 15
2018-05-14 09:47:05,123 [SERV] [1] NOTICE - CloudBerry Backup - Freeware. Version: 5.8.6.27
2018-05-14 09:47:16,438 [SERV] [1] NOTICE - Plan status: Success. Elapsed time: 00:00:23.4499764. Version: 5.8.6.27
2018-05-14 09:47:16,472 [SERV] [1] NOTICE - Scanned: 9340(93.6 GB). Uploaded: 0(0 bytes). Deleted: 0. Failed: 0
2018-05-14 09:47:16,524 [SERV] [1] NOTICE - Items added for backup: 0. Bytes sent: 0(0 bytes)

The NOTICE - Items added for backup: 3 means that the plan configuration files were uploaded b/c you modified the plan (you can check those files on the History | Files view). No new/modified files found.
Btw, a quick command to check a number of hidden files using cmd is:
dir *.* /s /A:H

Thanks, I found that I have about 240MB of GoPro files (.lrv) that it correctly did not upload. And a lot of thumb files. That accounts for a couple of hundred files but there's still the other few thousand and 30GB of files unaccounted for.

Is there any way to get an output of what it thinks it should or should not be backing up?

Thanks for your help.

Okay, thanks for an update. Let’s turn on high logging and re-run the plan. Go to the Tools | Options | Logging and set it to high level. Please send updated logs here.
Also it would be helpful to see the plan configuration file - this is a .cbb file located on the upper level of \Logs folder.

Thanks!

Ok, I did that but it still thinks everything eligible is backed up. I feel like the solution would be clear if I could identify just a few files that were skipped. AWS is awkward to work with, if there was a way to download a file list of what's on S3 that would help.

Or is there a way to query c:\programdata\cloudberrylab\cloudberry backup\data\cbbackup.db using SQL?

I can pick a small folder at random and try to backup just that again and hope it has something that will be skipping, but it's a shot in the dark.

2018-05-14 11:05:56,749 [PL] [4] INFO - Creating plan status monitor communication channel. Endpoint: net.pipe://localhost/CloudBerryLabCloudBerry Backup/CBBPlanStatusMonitor
2018-05-14 11:05:56,899 [SERV] [1] NOTICE - CloudBerry Backup - Freeware Engine Started. Version: 5.8.6.27
2018-05-14 11:05:56,941 [SERV] [1] NOTICE - Plan 7a6a9192-1b65-4e4c-98d4-bd2dac4caec5 'Backup plan on 2018-04-11 2:38:01 PM' (Plan). Force full mode :False
2018-05-14 11:05:56,946 [PL] [4] INFO - Channel 41825261 created.
2018-05-14 11:05:57,168 [Base] [1] WARN - Unknown .net version: 461308
2018-05-14 11:05:57,202 [Base] [1] WARN - Unknown .net version: 461308
2018-05-14 11:05:57,267 [PL] [1] INFO - Database file accessed: c:\programdata\cloudberrylab\cloudberry backup\data\cbbackup.db
2018-05-14 11:05:57,713 [PL] [1] INFO - Repository version: 5.8.0.142, created by product version: 5.8.6.27, date: 04/11/2018 11:57:45
2018-05-14 11:05:58,034 [Base] [1] INFO - All tasks removed from scheduler.
2018-05-14 11:05:58,210 [SERV] [1] INFO - Backup destination: backup-work7/WORK7
2018-05-14 11:05:58,244 [SERV] [1] INFO - Plan start mode: Normal
2018-05-14 11:05:58,279 [SERV] [1] INFO - Encryption is used: False
2018-05-14 11:05:58,316 [SERV] [1] INFO - Compression is used: False
2018-05-14 11:05:58,435 [SERV] [1] INFO - Purging old history records...
2018-05-14 11:05:58,488 [PL] [1] INFO - Prevented from sleep/hibernate
2018-05-14 11:05:58,521 [Base] [1] INFO - MemoryManager instance created
2018-05-14 11:05:58,564 [Base] [1] INFO - Chunks max memory usage is 364 MB
2018-05-14 11:05:58,627 [SERV] [1] INFO - Loading plan history...
2018-05-14 11:05:58,742 [PL] [1] INFO - CopyQueueCreator thread started
2018-05-14 11:05:58,780 [PL] [1] INFO - Delete temporary parts. Time: 00:00:00.0039936
2018-05-14 11:05:58,813 [PL] [1] INFO - Backup settings. Filter type: All, files filters:
2018-05-14 11:05:58,877 [PL] [1] INFO - Include system and hidden: False
2018-05-14 11:05:58,933 [PL] [1] INFO - Searching files with path: D:\media\sony-dump
2018-05-14 11:05:59,319 [PL] [1] INFO - Loading drive info d
2018-05-14 11:05:59,384 [PL] [1] INFO - Drive found: d, ID CE505765
2018-05-14 11:06:07,591 [PL] [1] INFO - CopyQueueCreator thread finished
2018-05-14 11:06:07,647 [PL] [1] INFO - Loading drive info for share cbb_configuration
2018-05-14 11:06:07,995 [CL] [13] INFO - The queue worker thread 13 started.
2018-05-14 11:06:08,242 [CL] [1] INFO - Item generated: C:\WINDOWS\TEMP\tmp77D5.tmp
2018-05-14 11:06:08,384 [PL] [1] INFO - Command added: Upload operation. Cloud path: backup-work7/CBB_WORK7/CBB_Configuration/enginesettings.list. IsSimple: True. Modified date: 14/05/2018 18:05:43. Size: 4 KB (4711)
2018-05-14 11:06:08,426 [PL] [1] INFO - Search thread is finished
2018-05-14 11:06:08,461 [PL] [1] INFO - Files to upload count: 1, Data size: 4711 (4 KB)
2018-05-14 11:06:08,493 [SERV] [1] INFO - Main thread. Waiting for upload complete event
2018-05-14 11:06:08,804 [CL] [13] INFO - Chunk 1 for backup-work7/CBB_WORK7/CBB_Configuration/enginesettings.list is ready for transfer. Size: 4711. Start offset: 0
2018-05-14 11:06:08,842 [S3] [13] INFO - InternalPutObjectNonChunked start, bucket: backup-work7, key: CBB_WORK7/CBB_Configuration/enginesettings.list, size: 4711
2018-05-14 11:06:09,198 [S3] [13] INFO - Putting object, bucket: backup-work7, key: CBB_WORK7/CBB_Configuration/enginesettings.list, length: 4711
2018-05-14 11:06:09,257 [S3] [13] INFO - Getting region for bucket: backup-work7
2018-05-14 11:06:16,597 [CL] [13] INFO - Multipart upload: uploaded as single file: 'backup-work7/CBB_WORK7/CBB_Configuration/enginesettings.list'
2018-05-14 11:06:16,672 [PL] [13] INFO - Command completed: Upload operation. Cloud path: backup-work7/CBB_WORK7/CBB_Configuration/enginesettings.list. IsSimple: True. Modified date: 14/05/2018 18:05:43. Size: 4 KB (4711)
2018-05-14 11:06:16,852 [PL] [13] INFO - 1 files copied (total size: 4 KB): CBB_Configuration\enginesettings.list
2018-05-14 11:06:16,888 [CL] [13] INFO - Running items count: 0, Awaiting: 0, Paused: 0, NA: 0, Failed: 0, SuccessCount: 0, WarningCount:0, 0 In progress count: 0, Idly Running count: 0
2018-05-14 11:06:16,918 [PL] [13] INFO - Entering sleeping mode event in CommandQueue occurred
2018-05-14 11:06:16,952 [PL] [13] INFO - Queue completed event fired
2018-05-14 11:06:16,982 [PL] [13] INFO - Upload queue is empty. Search thread is finished
2018-05-14 11:06:17,017 [PL] [13] INFO - Delete temporary parts. Time: 00:00:00.0039987
2018-05-14 11:06:17,129 [PL] [13] INFO - Setting waiting for complete
2018-05-14 11:06:17,161 [PL] [1] INFO - Backup engine wait completed
2018-05-14 11:06:18,192 [SERV] [1] INFO - Upload thread finished
2018-05-14 11:06:18,228 [SERV] [1] INFO - ImportFinalizing Start
2018-05-14 11:06:18,258 [SERV] [1] INFO - ImportFinalizing End
2018-05-14 11:06:18,330 [PL] [1] NOTICE - Creating purge queue started. Purge conditions: version count: 3
2018-05-14 11:06:18,441 [PL] [1] INFO - Files for purge with versions found: 1
2018-05-14 11:06:18,491 [PL] [1] NOTICE - Purge version search time: 00:00:00. Files checked for this plan: 0. Files for purge found: 0
2018-05-14 11:06:18,544 [PL] [1] NOTICE - Purge locally deleted search time: 00:00:00. Locally deleted files checked: 0. Files for purge found: 0
2018-05-14 11:06:18,637 [SERV] [1] INFO - Purging finished. Total files purged: 0
2018-05-14 11:06:18,675 [CL] [13] INFO - The queue worker thread 13 finished.
2018-05-14 11:06:18,903 [SERV] [1] NOTICE - Elapsed time: 00:00:21. Max memory usage: 59 MB. Processor time: 00:00:07. DB connection: 194 DB query: 283 Status report: 26
2018-05-14 11:06:18,935 [SERV] [1] NOTICE - CloudBerry Backup - Freeware. Version: 5.8.6.27
2018-05-14 11:06:19,037 [SERV] [1] INFO - Generating XML report to : C:\WINDOWS\TEMP\tmpA3E7.tmp
2018-05-14 11:06:19,085 [SERV] [1] INFO - -- META
2018-05-14 11:06:19,217 [SERV] [1] INFO - -- Records
2018-05-14 11:06:19,284 [SERV] [1] INFO - Generating XML report completed
2018-05-14 11:06:21,053 [PL] [1] INFO - Loading drive info for share cbb_report
2018-05-14 11:06:21,094 [CL] [1] INFO - Item generated: C:\WINDOWS\TEMP\tmpA3E7.tmp
2018-05-14 11:06:21,096 [CL] [12] INFO - The queue worker thread 12 started.
2018-05-14 11:06:21,219 [PL] [1] INFO - Command added: Upload operation. Cloud path: backup-work7/CBB_WORK7/CBB_Report/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html:/20180514180621/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html. IsSimple: False. Modified date: 14/05/2018 18:06:21. Size: 5 KB (5125)
2018-05-14 11:06:21,275 [PL] [1] INFO - Search thread is finished
2018-05-14 11:06:21,347 [PL] [1] INFO - Files to upload count: 1, Data size: 5125 (5 KB)
2018-05-14 11:06:21,562 [CL] [12] INFO - Chunk 1 for backup-work7/CBB_WORK7/CBB_Report/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html:/20180514180621/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html is ready for transfer. Size: 770. Start offset: 0
2018-05-14 11:06:21,594 [S3] [12] INFO - InternalPutObjectNonChunked start, bucket: backup-work7, key: CBB_WORK7/CBB_Report/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html:/20180514180621/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html, size: 770
2018-05-14 11:06:21,627 [S3] [12] INFO - Putting object, bucket: backup-work7, key: CBB_WORK7/CBB_Report/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html:/20180514180621/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html, length: 770
2018-05-14 11:06:22,094 [CL] [12] INFO - Multipart upload: uploaded as single file: 'backup-work7/CBB_WORK7/CBB_Report/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html:/20180514180621/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html'
2018-05-14 11:06:22,153 [PL] [12] INFO - Command completed: Upload operation. Cloud path: backup-work7/CBB_WORK7/CBB_Report/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html:/20180514180621/7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html. IsSimple: False. Modified date: 14/05/2018 18:06:21. Size: 5 KB (5125)
2018-05-14 11:06:22,262 [PL] [12] INFO - 1 files copied (total size: 770 bytes): CBB_Report\7a6a9192-1b65-4e4c-98d4-bd2dac4caec5.html
2018-05-14 11:06:22,298 [CL] [12] INFO - Running items count: 0, Awaiting: 0, Paused: 0, NA: 0, Failed: 0, SuccessCount: 0, WarningCount:0, 0 In progress count: 0, Idly Running count: 0
2018-05-14 11:06:22,330 [PL] [12] INFO - Entering sleeping mode event in CommandQueue occurred
2018-05-14 11:06:22,362 [PL] [12] INFO - Queue completed event fired
2018-05-14 11:06:22,392 [PL] [12] INFO - Upload queue is empty. Search thread is finished
2018-05-14 11:06:22,429 [PL] [12] INFO - Delete temporary parts. Time: 00:00:00.0040066
2018-05-14 11:06:22,563 [PL] [12] INFO - Setting waiting for complete
2018-05-14 11:06:22,604 [PL] [1] INFO - Backup engine wait completed
2018-05-14 11:06:22,689 [SERV] [1] INFO - Notification will be sent according to settings
2018-05-14 11:06:23,253 [SERV] [1] INFO - Notification has been successfully sent via CBL to jd
2018-05-14 11:06:23,291 [SERV] [1] NOTICE - Plan status: Success. Elapsed time: 00:00:25.3223639. Version: 5.8.6.27
2018-05-14 11:06:23,337 [SERV] [1] NOTICE - Scanned: 9340(93.6 GB). Uploaded: 1(4 KB). Deleted: 0. Failed: 0
2018-05-14 11:06:23,380 [SERV] [1] NOTICE - Items added for backup: 1. Bytes sent: 4711(4 KB)
2018-05-14 11:06:23,458 [PL] [1] INFO - Restored sleep/hibernate state

You can export backed up files to CSV from the History | Files view:

Awesome, well that's interesting because the CSV has ~9000 files in it, which suggests a complete set. I diffed it against a list of files on my drive and there was only 1 missing.

So I don't know what to make of the initial report, why does it say ~5000 files copied, when it seems to have done all ~9000?

Files to backup: 5025
Data to backup: 60 GB (64155161204 bytes)
Files copied: 5025
Data copied: 60 GB (64155161204 bytes)

If anyone else is interested in how I got a .csv of my local dir in CMD:
D:\media\sony-dump>(for /r %F in (*) do @echo "%~dpF","%~nxF",%~zF) >e:\dir.csv
then strip it down to the file paths on each line and sort, do the same for the CSV from Cloud Berry.

Btw we are going to have a Capacity report in coming 5.9 release that will show files/size details per each backup storage account.
Thanks for sharing your cmd script here! It can be useful for our customers. ;)