2.0.4.5 beta says: warnings, but no warnings (or errors) available in log

Support
1

I’ve just upgraded mono (to latest stable) and Duplicati (2.0.4.5 stable beta) and when running a backup the GUI tells me on completion that there is a warning. But when I look at the results, there are no errors or warnings, only some messages which look unproblematic:

DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 1126
OpenedFiles: 0
AddedFiles: 0
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 0
SizeOfExaminedFiles: 1518338033
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
    Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
    EndTime: 1/6/2019 10:54:09 PM (1546811649)
    BeginTime: 1/6/2019 10:54:08 PM (1546811648)
    Duration: 00:00:00.1268900
    Messages: [
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (87 bytes),
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00,
...
    ]
    Warnings: []
    Errors: []
    BackendStatistics:
        RemoteCalls: 5
        BytesUploaded: 0
        BytesDownloaded: 52495095
        FilesUploaded: 0
        FilesDownloaded: 3
        FilesDeleted: 0
        FoldersCreated: 0
        RetryAttempts: 0
        UnknownFileSize: 0
        UnknownFileCount: 0
        KnownFileCount: 87
        KnownFileSize: 1426848267
        LastBackupDate: 1/6/2019 10:52:07 PM (1546811527)
        BackupListCount: 5
        TotalQuotaSpace: 0
        FreeQuotaSpace: 0
        AssignedQuotaSpace: -1
        ReportedQuotaError: False
        ReportedQuotaWarning: False
        ParsedResult: Success
        Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
        Messages: [
            2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
            2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
            2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (87 bytes),
            2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
            2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00,
...
        ]
        Warnings: []
        Errors: []
RepairResults: null
TestResults:
    MainOperation: Test
    Verifications: [
        Key: duplicati-20180814T195514Z.dlist.zip.aes
        Value: [],
        Key: duplicati-ia3b16e5b587c417c8076456073aa2a68.dindex.zip.aes
        Value: [],
        Key: duplicati-b9753cc6fb22444d3a0414c52c1a2cf96.dblock.zip.aes
        Value: []
    ]
    ParsedResult: Success
    Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
    EndTime: 1/6/2019 10:54:13 PM (1546811653)
    BeginTime: 1/6/2019 10:54:09 PM (1546811649)
    Duration: 00:00:04.3125280
    Messages: [
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (87 bytes),
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
        2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00,
...
    ]
    Warnings: []
    Errors: []
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 1/6/2019 10:54:13 PM (1546811653)
BeginTime: 1/6/2019 10:54:07 PM (1546811647)
Duration: 00:00:05.5277420
Messages: [
    2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
    2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),
    2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (87 bytes),
    2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
    2019-01-06 22:54:08 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00,
...
]
Warnings: []
Errors: []

Is there an explanation?

2

How did Duplicati tell you there was an warning?

Could you provide an screenshot?

Was it something like “Warning - Got 0 warnings” or similar?

3

It was the red panel that appears at the end of a run and it says there is 1 warning.

50
Screen Shot 2019-01-07 at 7 January 18.53.50.png954×696 43.4 KB

4

That panel tends to always link to the job log even if the warning/error was a global one - did you try look at the main About -> “Show log” tab to see if a warning was there?

My guess is a parameter your job uses was deprecated and that’s what’s being complained about.

5

No warnings there. Only a few errors from longer ago, all “Error in updater”. So, that’s not it.

6

How do I get a bit more logging? might be worth revisiting. There’s usually a warning somewhere to be caught. Beyond the known multiple-logs awkwardness though, I’m not sure why they’re not caught by normal means…

7

I’ve not managed to get my email notification to work therefor Duplicati is throwing up a warning on every backup job.
@ gctwnl
Could it be that you are seeing the same kind of warnings?

8

I’m seeing this same issue on my Synology NAS. I can’t find any warnings in any of the job logs.
I also have Duplicati configured to send an email if a warning occurs, but I get no such emails.

9

Ah, this could be it. It seems to have to do with mono certificate handling:

{
	"ClassName": "System.AggregateException",
	"Message": "One or more errors occurred.",
	"Data": null,
	"InnerException": {
		"ClassName": "System.Security.Authentication.AuthenticationException",
		"Message": "Authentication failed, see inner exception.",
		"Data": null,
		"InnerException": {
			"ClassName": "Mono.Security.Interface.TlsException",
			"Message": "CertificateUnknown",
			"Data": null,
			"InnerException": null,
			"HelpURL": null,
			"StackTraceString": "  at Mono.AppleTls.AppleTlsContext.EvaluateTrust () [0x000d1] in <4605a50878ff458c98a8b66722729be6>:0 \n  at Mono.AppleTls.AppleTlsContext.ProcessHandshake () [0x0004e] in <4605a50878ff458c98a8b66722729be6>:0 \n  at Mono.Net.Security.MobileAuthenticatedStream.ProcessHandshake (Mono.Net.Security.AsyncOperationStatus status, System.Boolean renegotiate) [0x000a1] in <4605a50878ff458c98a8b66722729be6>:0 \n  at (wrapper remoting-invoke-with-check) Mono.Net.Security.MobileAuthenticatedStream.ProcessHandshake(Mono.Net.Security.AsyncOperationStatus,bool)\n  at Mono.Net.Security.AsyncHandshakeRequest.Run (Mono.Net.Security.AsyncOperationStatus status) [0x00006] in <4605a50878ff458c98a8b66722729be6>:0 \n  at Mono.Net.Security.AsyncProtocolRequest.ProcessOperation (System.Threading.CancellationToken cancellationToken) [0x000ff] in <4605a50878ff458c98a8b66722729be6>:0 \n  at Mono.Net.Security.AsyncProtocolRequest.StartOperation (System.Threading.CancellationToken cancellationToken) [0x0008b] in <4605a50878ff458c98a8b66722729be6>:0 ",
			"RemoteStackTraceString": null,
			"RemoteStackIndex": 0,
			"ExceptionMethod": null,
			"HResult": -2146233088,
			"Source": "mscorlib"
		},
		"HelpURL": null,
		"StackTraceString": "  at Mono.Net.Security.MobileAuthenticatedStream.ProcessAuthentication (System.Boolean runSynchronously, Mono.Net.Security.MonoSslAuthenticationOptions options, System.Threading.CancellationToken cancellationToken) [0x00252] in <4605a50878ff458c98a8b66722729be6>:0 ",
		"RemoteStackTraceString": null,
		"RemoteStackIndex": 0,
		"ExceptionMethod": null,
		"HResult": -2146233087,
		"Source": "mscorlib"
	},
	"HelpURL": null,
	"StackTraceString": "  at Duplicati.Library.Modules.Builtin.SendMail.SendMessage (System.String subject, System.String body) [0x00581] in <3a3628a68be44e7d8c6dd8573b883642>:0 \n  at Duplicati.Library.Modules.Builtin.ReportHelper.OnFinish (System.Object result) [0x00138] in <3a3628a68be44e7d8c6dd8573b883642>:0 ",
	"RemoteStackTraceString": null,
	"RemoteStackIndex": 0,
	"ExceptionMethod": null,
	"HResult": -2146233088,
	"Source": "Duplicati.Library.Modules.Builtin",
	"InnerExceptions": [{
		"ClassName": "System.Security.Authentication.AuthenticationException",
		"Message": "Authentication failed, see inner exception.",
		"Data": null,
		"InnerException": {
			"ClassName": "Mono.Security.Interface.TlsException",
			"Message": "CertificateUnknown",
			"Data": null,
			"InnerException": null,
			"HelpURL": null,
			"StackTraceString": "  at Mono.AppleTls.AppleTlsContext.EvaluateTrust () [0x000d1] in <4605a50878ff458c98a8b66722729be6>:0 \n  at Mono.AppleTls.AppleTlsContext.ProcessHandshake () [0x0004e] in <4605a50878ff458c98a8b66722729be6>:0 \n  at Mono.Net.Security.MobileAuthenticatedStream.ProcessHandshake (Mono.Net.Security.AsyncOperationStatus status, System.Boolean renegotiate) [0x000a1] in <4605a50878ff458c98a8b66722729be6>:0 \n  at (wrapper remoting-invoke-with-check) Mono.Net.Security.MobileAuthenticatedStream.ProcessHandshake(Mono.Net.Security.AsyncOperationStatus,bool)\n  at Mono.Net.Security.AsyncHandshakeRequest.Run (Mono.Net.Security.AsyncOperationStatus status) [0x00006] in <4605a50878ff458c98a8b66722729be6>:0 \n  at Mono.Net.Security.AsyncProtocolRequest.ProcessOperation (System.Threading.CancellationToken cancellationToken) [0x000ff] in <4605a50878ff458c98a8b66722729be6>:0 \n  at Mono.Net.Security.AsyncProtocolRequest.StartOperation (System.Threading.CancellationToken cancellationToken) [0x0008b] in <4605a50878ff458c98a8b66722729be6>:0 ",
			"RemoteStackTraceString": null,
			"RemoteStackIndex": 0,
			"ExceptionMethod": null,
			"HResult": -2146233088,
			"Source": "mscorlib"
		},
		"HelpURL": null,
		"StackTraceString": "  at Mono.Net.Security.MobileAuthenticatedStream.ProcessAuthentication (System.Boolean runSynchronously, Mono.Net.Security.MonoSslAuthenticationOptions options, System.Threading.CancellationToken cancellationToken) [0x00252] in <4605a50878ff458c98a8b66722729be6>:0 ",
		"RemoteStackTraceString": null,
		"RemoteStackIndex": 0,
		"ExceptionMethod": null,
		"HResult": -2146233087,
		"Source": "mscorlib"
	}]
}

No idea why, though (probably sending mail) or how to fix (I’d like to know for sure before fixing).

10

I tweaked your post to make the error message a bit easier to read.

Unfortunately, I don’t have any suggestion on how to resolve the actual issue unless this SSL TLS support in Mono page helps:

11

FAQ: Security – Secure Socket Layer (SSL) / Transport Layer Security (TLS) has info from the Mono team. Although I don’t know if it’s the same version, you can try mono TlsTest.exe from Duplicati’s utility-scripts. Unless you set up DNS over TLS, I’d guess that the first chance to get a TLS error is with your email server, although that would be more sure if MailKit actually showed up in the errors (or did it?), e.g. as shown here.

12

That panel tends to always link to the job log even if the warning/error was a global one

…okay. And how is the user supposed to know that the error was global instead of job related? And that the global log is buried in the About section of the UI? This is definitely an issue I had when I was trying to figure out why my restores were failing, and it was very frustrating that “show” never showed any errors.

  • It should be obvious to the end user that there are job logs and global logs
  • If the warnings are global vs job related, the error should say that.
  • The “show” button in a dialog warning the user of errors should show the error in question, regardless of where it appears
  • The logs should be visible from the main UI, not buried in a credits section
1 Like
13

Interestingly, the first TlsTest.exe works, the second doesn’t (so we’re on to something here).

luna-wifi:utility-scripts gerben$ mono TlsTest.exe --web https://github.com
https://github.com
luna-wifi:utility-scripts gerben$ mono TlsTest.exe --stream https://github.com
https://github.com
FAILED: #-2146232800
System.IO.IOException: The authentication or decryption has failed. ---&gt; System.IO.IOException: The authentication or decryption has failed. ---&gt; Mono.Security.Protocol.Tls.TlsException: The authentication or decryption has failed.
at Mono.Security.Protocol.Tls.RecordProtocol.EndReceiveRecord (System.IAsyncResult asyncResult) [0x00037] in &lt;5e40cb1beec24ebd9c944005a98819e3&gt;:0
at Mono.Security.Protocol.Tls.SslClientStream.SafeEndReceiveRecord (System.IAsyncResult ar, System.Boolean ignoreEmpty) [0x00000] in &lt;5e40cb1beec24ebd9c944005a98819e3&gt;:0
at Mono.Security.Protocol.Tls.SslClientStream.NegotiateAsyncWorker (System.IAsyncResult result) [0x00071] in &lt;5e40cb1beec24ebd9c944005a98819e3&gt;:0
--- End of inner exception stack trace ---
at Mono.Security.Protocol.Tls.SslClientStream.EndNegotiateHandshake (System.IAsyncResult result) [0x00032] in &lt;5e40cb1beec24ebd9c944005a98819e3&gt;:0
at Mono.Security.Protocol.Tls.SslStreamBase.AsyncHandshakeCallback (System.IAsyncResult asyncResult) [0x0000c] in &lt;5e40cb1beec24ebd9c944005a98819e3&gt;:0
--- End of inner exception stack trace ---
at Mono.Security.Protocol.Tls.SslStreamBase.EndNegotiateHandshake (Mono.Security.Protocol.Tls.SslStreamBase+InternalAsyncResult asyncResult) [0x00022] in &lt;5e40cb1beec24ebd9c944005a98819e3&gt;:0
at Mono.Security.Protocol.Tls.SslStreamBase.NegotiateHandshake () [0x0002b] in &lt;5e40cb1beec24ebd9c944005a98819e3&gt;:0
at Mono.Security.Protocol.Tls.SslStreamBase.Write (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00064] in &lt;5e40cb1beec24ebd9c944005a98819e3&gt;:0
at System.IO.StreamWriter.Flush (System.Boolean flushStream, System.Boolean flushEncoder) [0x0007e] in &lt;ab7d7c14aa7a405ca7d85082a965a195&gt;:0
at System.IO.StreamWriter.Flush () [0x00006] in &lt;ab7d7c14aa7a405ca7d85082a965a195&gt;:0
at TlsTest.GetStreamPage (System.String url) [0x000e1] in &lt;ef0b674f44354433abea9f21ff95c135&gt;:0
at TlsTest.Main (System.String[] args) [0x0030a] in &lt;ef0b674f44354433abea9f21ff95c135&gt;:0

I did update mono to 5.18.0.225 recently on this system.

14

They’re not, and they shouldn’t need to. The error logging was rewritten fairly recently and this just hasn’t been cleaned up yet. A number of functional / performance issues popped up at the same time and basically all effort went into addressing them.

If you’ve got the time, or know somebody who does, please feel free to jump in and tackle this or any other issue / deficiency that crops up. :slight_smile:

Do you recall what version you were using before and whether you had any of the same issues with it?

15

I’m afraid not. I updated on Jan 6, so might I be able to find this information in (Duplicati) logging that still exists?

16

Hmm…I think Duplicati version was added to logs but not mono version. Oh, well - thanks anyway.

17

Just bumped into this - how do you feel about downgrading mono?

18

Not that important. I am however not running brew’s mono but the one from the Mono project (installer package). And the question is: to what version?