[2.0.3.5] Always warnings, but what is the warning?

Tapio · May 22, 2018, 3:45pm

Hi, in 2.0.3.5, but also 2.0.3.6 (I reverted back), I get those red, frightening warnings. But in the log I see no warning. Just a lot of stuff. What does Duplicati do here - except frightening me? I deleted+repair DBs, no change.

EDIT: I don’t know how to properly post code.

DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 51019
OpenedFiles: 0
AddedFiles: 131
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 0
SizeOfExaminedFiles: 201828291973
SizeOfOpenedFiles: 0
NotProcessedFiles: 0
AddedFolders: 0
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
CompactResults: null
DeleteResults:
    DeletedSets: []
    Dryrun: False
    MainOperation: Delete
    CompactResults: null
    ParsedResult: Success
    EndTime: 22.05.2018 16:05:00 (1526997900)
    BeginTime: 22.05.2018 16:04:52 (1526997892)
    Duration: 00:00:08.1264648
    Messages: [
        2018-05-22 16:02:39 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
        2018-05-22 16:02:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
        2018-05-22 16:04:33 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (6,84 KB),
        2018-05-22 16:04:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20180522T140239Z.dlist.zip.aes (5,33 MB),
        2018-05-22 16:04:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20180522T140239Z.dlist.zip.aes (5,33 MB),
...
    ]
    Warnings: []
    Errors: []
    BackendStatistics:
        RemoteCalls: 6
        BytesUploaded: 5584557
        BytesDownloaded: 57968103
        FilesUploaded: 1
        FilesDownloaded: 3
        FilesDeleted: 0
        FoldersCreated: 0
        RetryAttempts: 0
        UnknownFileSize: 0
        UnknownFileCount: 0
        KnownFileCount: 7010
        KnownFileSize: 182635564666
        LastBackupDate: 22.05.2018 16:02:39 (1526997759)
        BackupListCount: 8
        TotalQuotaSpace: 1099511627776
        FreeQuotaSpace: 483302332021
        AssignedQuotaSpace: -1
        ReportedQuotaError: False
        ReportedQuotaWarning: False
        ParsedResult: Success
        Messages: [
            2018-05-22 16:02:39 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
            2018-05-22 16:02:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
            2018-05-22 16:04:33 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (6,84 KB),
            2018-05-22 16:04:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20180522T140239Z.dlist.zip.aes (5,33 MB),
            2018-05-22 16:04:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20180522T140239Z.dlist.zip.aes (5,33 MB),
...
        ]
        Warnings: []
        Errors: []
RepairResults: null
TestResults:
    MainOperation: Test
    Verifications: [
        Key: duplicati-20180522T140239Z.dlist.zip.aes
        Value: [],
        Key: duplicati-i5eab49e978b8487ea65e5bf22beae207.dindex.zip.aes
        Value: [],
        Key: duplicati-bac00547d265a48a2b4836d55ebbb8b4f.dblock.zip.aes
        Value: []
    ]
    ParsedResult: Success
    EndTime: 22.05.2018 16:07:11 (1526998031)
    BeginTime: 22.05.2018 16:06:15 (1526997975)
    Duration: 00:00:56.8082492
    Messages: [
        2018-05-22 16:02:39 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
        2018-05-22 16:02:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
        2018-05-22 16:04:33 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (6,84 KB),
        2018-05-22 16:04:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20180522T140239Z.dlist.zip.aes (5,33 MB),
        2018-05-22 16:04:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20180522T140239Z.dlist.zip.aes (5,33 MB),
...
    ]
    Warnings: []
    Errors: []
ParsedResult: Success
EndTime: 22.05.2018 16:07:11 (1526998031)
BeginTime: 22.05.2018 16:02:39 (1526997759)
Duration: 00:04:32.3535778
Messages: [
    2018-05-22 16:02:39 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
    2018-05-22 16:02:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
    2018-05-22 16:04:33 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (6,84 KB),
    2018-05-22 16:04:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20180522T140239Z.dlist.zip.aes (5,33 MB),
    2018-05-22 16:04:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20180522T140239Z.dlist.zip.aes (5,33 MB),
...
]
Warnings: []
Errors: []

JonMikelV · May 23, 2018, 3:52am

Most likely the error is shown in one of the log tables from a database. Since it’s not in the job email my guess is it won’t be in the job log (though you could try looking at the “Remote” tab, just in case I’m wrong).

Try using the main menu About link then choose the “Show log” button. It might be under “Stored” but if not check under “Live” and choose the “Error” filter option from the list.

Tapio · May 23, 2018, 12:03pm

Thanks, now I see the messages, but: what is it telling me here?

System.Threading.ThreadAbortException: Der Thread wurde abgebrochen. bei System.Data.SQLite.SQLiteCommand.ExecuteReader(CommandBehavior behavior) bei Duplicati.Library.Main.Database.ExtensionMethods.ExecuteScalarInt64(IDbCommand self, String cmd, Int64 defaultvalue, Object[] values) bei Duplicati.Library.Main.Database.LocalDatabase.GetBlocksLargerThan(Int64 fhblocksize) bei Duplicati.Library.Main.Utility.VerifyParameters(LocalDatabase db, Options options, IDbTransaction transaction) bei Duplicati.Library.Main.Operation.BackupHandler.Run(String[] sources, IFilter filter) bei Duplicati.Library.Main.Controller.<>c__DisplayClass15_0.<Backup>b__0(BackupResults result) bei Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method) bei Duplicati.Library.Main.Controller.Backup(String[] inputsources, IFilter filter) bei Duplicati.Server.Runner.Run(IRunnerData data, Boolean fromQueue)

JonMikelV · May 24, 2018, 4:11pm

In my recent experience the only time I’ve seen ThreadAbortException errors is when I stop a currently running task such as with ctrl-c with a command line run or “Abort” in the GUI and choosing “now” instead of “after next upload”.

I don’t suppose any of those things were happening when you got those errors?

I should also point out that a thread abort is usually a fatal error (as in the backup failed) while a warning usually means the backup finished but something unexpected happened such as a file being in use so it couldn’t be backed up.

We’d have to dig a bit more but the ParsedResult: Success in your log/email above looks to me like the backup step is finishing just fine but then something else (perhaps a cleanup step) outside of that logging area is having a problem.

Tapio · May 24, 2018, 4:44pm

It happens at every backup. Every time, every backup set. Yes, to my knowledge it creates the backups but still reports those errors.

JonMikelV · May 25, 2018, 6:50pm

Assuming I’m following the translation correctly, the abort is happening while running SQL as part of the GetBlocksLargerThan() process that basically checks to make sure all your blocks are the same size.

However, I would expect a failure in that step to cause the whole backup to fail which isn’t what seems to be happening to you.

What is the log entry just before the error?

JonMikelV · May 29, 2018, 4:45pm

A post was split to a new topic: Access to $RECYCLE.BIN denied

techwright · December 13, 2018, 1:23pm

Did you ever get a resolution to this error? I’m having the same issue. I have 3 backups running on my PC and each one gives me a warning every time it runs. I have that same ThreadAbortException.

I never had an issue but somehow my database became corrupt and I had to do some recreations/repairs to it and after that this warning started coming up. My post on the DB issues here

He is my error:

    System.Threading.ThreadAbortException: Thread was being aborted.
   at System.Threading.WaitHandle.WaitOneNative(SafeHandle waitableSafeHandle, UInt32 millisecondsTimeout, Boolean hasThreadAffinity, Boolean exitContext)
   at System.Threading.WaitHandle.InternalWaitOne(SafeHandle waitableSafeHandle, Int64 millisecondsTimeout, Boolean hasThreadAffinity, Boolean exitContext)
   at System.Threading.WaitHandle.WaitOne(Int32 millisecondsTimeout, Boolean exitContext)
   at Duplicati.Server.EventPollNotify.Wait(Int64 eventId, Int32 milliseconds)
   at Duplicati.Server.WebServer.RESTMethods.RequestInfo.LongPollCheck(EventPollNotify poller, Int64& id, Boolean& isError)
   at Duplicati.Server.WebServer.RESTMethods.ServerState.GET(String key, RequestInfo info)
   at Duplicati.Server.WebServer.RESTHandler.DoProcess(RequestInfo info, String method, String module, String key)

I also have this error too, not sure which one is triggering the warning because I only get one warning…

System.ObjectDisposedException: Cannot write to a closed TextWriter.
   at System.IO.__Error.WriterClosed()
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder)
   at Duplicati.Server.WebServer.RESTHandler.DoProcess(RequestInfo info, String method, String module, String key)

bling26 · January 29, 2019, 8:42pm

I to am getting warnings with everything I am doing. My backups seem to be successful however if I try to restore anything I only receive warning after warning but never any explanation. Everything was working so well too and nothing has changed to my knowledge besides Windows Updates.

ts678 · January 29, 2019, 11:25pm

Where are you looking? Duplicati currently (I believe) has warning popups that send one to the job log at Job → Show log → General, however the server component of Duplicati (used if you use the browser GUI) can leave messages at About → Show log → Stored. If somehow that’s not enough, one can try watching About → Show log → Live, or setting up a –log-file. If you can find a warning, please detail it in a new support post.

bling26 · January 30, 2019, 7:48pm

It seems that I get warning for everything I try to do now whether it is backup, restore, or repair. The most current warning I received was today after my daily backup. This warning actually has a show button available and when that is pressed, it shows me the following:

DeletedFiles: 84
DeletedFolders: 16
ModifiedFiles: 0
ExaminedFiles: 70850
OpenedFiles: 84
AddedFiles: 84
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 4117617
SizeOfExaminedFiles: 4033994299472
SizeOfOpenedFiles: 4117617
NotProcessedFiles: 0
AddedFolders: 16
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
CompactResults:
DeletedFileCount: 0
DownloadedFileCount: 0
UploadedFileCount: 0
DeletedFileSize: 0
DownloadedFileSize: 0
UploadedFileSize: 0
Dryrun: False
MainOperation: Compact
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 1/30/2019 2:07:53 AM (1548835673)
BeginTime: 1/30/2019 2:03:18 AM (1548835398)
Duration: 00:04:34.5312480
Messages: [
2019-01-30 01:00:00 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2019-01-30 01:06:20 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2019-01-30 01:06:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (1.50 KB),
2019-01-30 01:48:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
2019-01-30 01:48:36 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
…
]
Warnings:
Errors:
BackendStatistics:
RemoteCalls: 9
BytesUploaded: 8471287
BytesDownloaded: 5380748439
FilesUploaded: 3
FilesDownloaded: 3
FilesDeleted: 1
FoldersCreated: 0
RetryAttempts: 0
UnknownFileSize: 0
UnknownFileCount: 0
KnownFileCount: 1535
KnownFileSize: 4036730279187
LastBackupDate: 1/30/2019 1:00:02 AM (1548831602)
BackupListCount: 7
TotalQuotaSpace: 7993335717888
FreeQuotaSpace: 3956114513920
AssignedQuotaSpace: -1
ReportedQuotaError: False
ReportedQuotaWarning: False
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
Messages: [
2019-01-30 01:00:00 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2019-01-30 01:06:20 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2019-01-30 01:06:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (1.50 KB),
2019-01-30 01:48:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
2019-01-30 01:48:36 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
…
]
Warnings:
Errors:
DeleteResults:
DeletedSets: [
Item1: 5
Item2: 1/23/2019 1:00:05 AM (1548226805)
]
Dryrun: False
MainOperation: Delete
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 1/30/2019 2:07:53 AM (1548835673)
BeginTime: 1/30/2019 1:48:59 AM (1548834539)
Duration: 00:18:53.6562489
Messages: [
2019-01-30 01:00:00 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2019-01-30 01:06:20 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2019-01-30 01:06:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (1.50 KB),
2019-01-30 01:48:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
2019-01-30 01:48:36 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
…
]
Warnings:
Errors:
RepairResults: null
TestResults:
MainOperation: Test
Verifications: [
Key: duplicati-20190130T070002Z.dlist.zip.aes
Value: ,
Key: duplicati-ice52b4ba936342e888388e37a4c5a8f1.dindex.zip.aes
Value: ,
Key: duplicati-bb183abd63d454d0cadc9b286cdec42ff.dblock.zip.aes
Value:
]
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 1/30/2019 2:08:48 AM (1548835728)
BeginTime: 1/30/2019 2:07:53 AM (1548835673)
Duration: 00:00:55.2031269
Messages: [
2019-01-30 01:00:00 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2019-01-30 01:06:20 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2019-01-30 01:06:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (1.50 KB),
2019-01-30 01:48:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
2019-01-30 01:48:36 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
…
]
Warnings:
Errors:
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 1/30/2019 2:08:49 AM (1548835729)
BeginTime: 1/30/2019 1:00:00 AM (1548831600)
Duration: 01:08:48.7968704
Messages: [
2019-01-30 01:00:00 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2019-01-30 01:06:20 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2019-01-30 01:06:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (1.50 KB),
2019-01-30 01:48:33 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
2019-01-30 01:48:36 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b26117c66a78d410095226a047d64d0d2.dblock.zip.aes (137.95 KB),
…
]
Warnings:
Errors:

bling26 · January 30, 2019, 8:49pm

If attempt to do a restore, this is what shows up at the bottom of my screen before I even select the date or files??? I do not see a way to investigate these warnings.

ts678 · January 30, 2019, 11:03pm

Please follow the directions given before. The first sentence is what you tried, but it’s often not sufficient. There are three other ways. The first two need no setting changes, but the --log-file one does, so is last.

Viewing the log files of a backup job is what you posted, and probably what the Show button will open up.

Viewing the Duplicati Server Logs is because sometimes the server component logs its own messages. This section also mentions the Live button where you can watch in a different browser tab if that’s easier.

Adding --log-file option (sometimes along with –log-file-log-level, however warnings log by default) is next.

bling26 · January 31, 2019, 9:50pm

Thank you for the detailed response. I attempted to do what was listed however it seems all my issues have resolved themselves. I will continue to look into them and post if anything comes back up. The only thing left for me to do is set up some sort of email notifications