Hi there,
I do not receive mail reports from my scheduled backup jobs. Just upgraded to version 2.0.3.12_canary_2018-10-23 to see if it resolved anything, but no. The strange thing is that when I test the configuration in command line (both “send-mail” and “backup”), it all works and I receive the mail report! It runs on a QNAP NAS. App compilation is from qnapclub.eu.
I have no clue what the difference is between the two methods and I need help, please.
My static configuration:
--compression-module="zip"
--compression-extension-file="/share/CACHEDEV1_DATA/.qpkg/Duplicati/Duplicati/default_compressed_extensions.txt"
--debug-retry-errors=true
--send-mail-any-operation=true
--send-mail-body="%RESULT%"
--send-mail-from="Duplicati Backup <...@gmail.com>"
--send-mail-level="all"
--send-mail-subject="%PARSEDRESULT% - Duplicati %OPERATIONNAME% report"
--send-mail-to="Me <...@gmail.com>"
--send-mail-url="smtp://smtp.gmail.com:587/?starttls=when-available"
--send-mail-username="...@gmail.com"
--send-mail-password="..."
--console-log-level=Verbose
My command line configuration:
--compression-module=zip --compression-extension-file="/share/CACHEDEV1_DATA/.qpkg/Duplicati/Duplicati/default_compressed_extensions.txt" --debug-retry-errors=true --send-mail-any-operation=true --send-mail-body="%RESULT%" --send-mail-from="Duplicati Backup <...@gmail.com>" --send-mail-level="all" --send-mail-subject="%PARSEDRESULT% - Duplicati %OPERATIONNAME% report" --send-mail-to="Me <...@gmail.com>" --send-mail-url="smtp://smtp.gmail.com:587/?starttls=when-available" --send-mail-username="...@gmail.com" --send-mail-password="..." --console-log-level=Verbose --full-result=true --backup-name=Backup --dbpath=/share/CACHEDEV1_DATA/.qpkg/Duplicati/.config/Duplicati/72857877698674868879.sqlite --encryption-module=aes --dblock-size=50mb --passphrase=... --retention-policy=1W:1D,4W:1W,12M:1M --disable-module=console-password-input
My command line log from a successfully execution of send-mail:
The operation SendMail has started Hele SMTP-kommunikationen: Connected to smtp://smtp.gmail.com:587/?starttls=when-available S: 220 smtp.gmail.com ESMTP d64-v6sm175545edd.29 - gsmtp C: EHLO [<IP>] S: 250-smtp.gmail.com at your service, [...] S: 250-SIZE 35882577 S: 250-8BITMIME S: 250-STARTTLS S: 250-ENHANCEDSTATUSCODES S: 250-PIPELINING S: 250-CHUNKING S: 250 SMTPUTF8 C: STARTTLS S: 220 2.0.0 Ready to start TLS C: EHLO [<IP>] S: 250-smtp.gmail.com at your service, [...] S: 250-SIZE 35882577 S: 250-8BITMIME S: 250-AUTH LOGIN PLAIN XOAUTH2 PLAIN-CLIENTTOKEN OAUTHBEARER XOAUTH S: 250-ENHANCEDSTATUSCODES S: 250-PIPELINING S: 250-CHUNKING S: 250 SMTPUTF8 C: AUTH XOAUTH2 ... S: 334 ... C: AUTH PLAIN ... S: 535-5.7.8 Username and Password not accepted. Learn more at S: 535 5.7.8 https://support.google.com/mail/?p=BadCredentials d64-v6sm175545edd.29 - gsmtp C: AUTH LOGIN S: 334 ... C: ... S: 334 ... C: ... S: 235 2.7.0 Accepted C: MAIL FROM:<...@gmail.com> C: RCPT TO:<...@gmail.com> S: 250 2.1.0 OK d64-v6sm175545edd.29 - gsmtp S: 250 2.1.5 OK d64-v6sm175545edd.29 - gsmtp C: DATA S: 354 Go ahead d64-v6sm175545edd.29 - gsmtp C: From: Duplicati Backup <...@gmail.com> C: Date: Sun, 28 Oct 2018 11:53:19 +0100 C: Subject: Success - Duplicati SendMail report C: Message-Id: <...> C: To: Me <...@gmail.com> C: MIME-Version: 1.0 C: Content-Type: text/plain; charset=utf-8 C: Content-Transfer-Encoding: 7bit C: C: MainOperation: SendMail C: Lines: [] C: ParsedResult: Success C: Version: 2.0.3.12 (2.0.3.12_canary_2018-10-23) C: EndTime: 10/28/2018 11:53:19 AM (1540723999) C: BeginTime: 10/28/2018 11:53:19 AM (1540723999) C: Duration: 00:00:00.0402790 C: C: . S: 250 2.0.0 OK 1540724000 d64-v6sm175545edd.29 - gsmtp C: QUIT S: 221 2.0.0 closing connection d64-v6sm175545edd.29 - gsmtp Email sendt med succes ved hjælp af server: smtp://smtp.gmail.com:587/?starttls=when-available Email sendt med succes ved hjælp af server: smtp://smtp.gmail.com:587/?starttls=when-available Return code: 0
I wonder why the log at first fail login and afterwards succeed…
A backup log from a manual job execution:
DeletedFiles: 0 DeletedFolders: 0 ModifiedFiles: 0 ExaminedFiles: 119467 OpenedFiles: 0 AddedFiles: 0 SizeOfModifiedFiles: 0 SizeOfAddedFiles: 0 SizeOfExaminedFiles: 195236679400 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.3.12 (2.0.3.12_canary_2018-10-23) EndTime: 10/28/2018 12:57:10 PM (1540727830) BeginTime: 10/28/2018 12:56:45 PM (1540727805) Duration: 00:00:25.3684180 Messages: [ 2018-10-28 12:48:43 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started, 2018-10-28 12:52:50 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (), 2018-10-28 12:53:31 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (6,61 KB), 2018-10-28 12:56:45 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed, 2018-10-28 12:56:45 +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: 63174839 FilesUploaded: 0 FilesDownloaded: 3 FilesDeleted: 0 FoldersCreated: 0 RetryAttempts: 0 UnknownFileSize: 0 UnknownFileCount: 0 KnownFileCount: 6770 KnownFileSize: 177084970810 LastBackupDate: 10/27/2018 12:12:19 AM (1540591939) BackupListCount: 6 TotalQuotaSpace: 0 FreeQuotaSpace: 0 AssignedQuotaSpace: -1 ReportedQuotaError: False ReportedQuotaWarning: False ParsedResult: Success Version: 2.0.3.12 (2.0.3.12_canary_2018-10-23) Messages: [ 2018-10-28 12:48:43 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started, 2018-10-28 12:52:50 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (), 2018-10-28 12:53:31 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (6,61 KB), 2018-10-28 12:56:45 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed, 2018-10-28 12:56:45 +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-....dlist.zip.aes Value: [], Key: duplicati-....dindex.zip.aes Value: [], Key: duplicati-.....dblock.zip.aes Value: [] ] ParsedResult: Success Version: 2.0.3.12 (2.0.3.12_canary_2018-10-23) EndTime: 10/28/2018 12:58:32 PM (1540727912) BeginTime: 10/28/2018 12:57:44 PM (1540727864) Duration: 00:00:47.8916150 Messages: [ 2018-10-28 12:48:43 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started, 2018-10-28 12:52:50 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (), 2018-10-28 12:53:31 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (6,61 KB), 2018-10-28 12:56:45 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed, 2018-10-28 12:56:45 +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.3.12 (2.0.3.12_canary_2018-10-23) EndTime: 10/28/2018 12:58:32 PM (1540727912) BeginTime: 10/28/2018 12:48:43 PM (1540727323) Duration: 00:09:48.9079800 Messages: [ 2018-10-28 12:48:43 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started, 2018-10-28 12:52:50 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (), 2018-10-28 12:53:31 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (6,61 KB), 2018-10-28 12:56:45 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed, 2018-10-28 12:56:45 +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: []
Any help is appreciated!
Regards,
Kudo