dupReport not picking up emails from Duplicati.

HandyGuySoftware commented 3 years ago

Reported by Matt Bridges:

MattBridges

Hi, I’m probably doing something silly but I’ve configured Duplicati to send me emails on completion of a backup task which it does and dupReport is sending me summary emails but it’s not picking up the email from Duplicati? The name of the backup is Unraid-Backblaze, is there something else I need to configure?

HandyGuySoftware commented 3 years ago

Matt,

Please upload your .rc file and the dupreport.log file produced by the program. Between those two we should be able to determine what's going on.

eldudemeister commented 3 years ago

Thanks! https://pastebin.pl/view/f4578d1f .rc uploaded to pastebin in the link. Log file pasted below...

[2020-11-22T13:56:11.284141][NOTICE][main][startup]dupReport Log - Start
[2020-11-22T13:56:11.284186][NOTICE][main][startup]Program Version 3.0.1 Release
[2020-11-22T13:56:11.284202][NOTICE][main][startup]Database Version 3.0.0
[2020-11-22T13:56:11.284214][NOTICE][main][startup]Python version 3.7.3 (default, Jul 25 2020, 13:03:44)
[GCC 8.3.0]
[2020-11-22T13:56:11.284226][NOTICE][main][startup]Program path: /home/matt/dupReport
[2020-11-22T13:56:11.284239][NOTICE][Options][initOptions]Initializing global program options.
[2020-11-22T13:56:11.284251][NOTICE][Options][OptionManager]Initializing option manager.
[2020-11-22T13:56:11.284262][NOTICE][Options][processCmdLineArgs]Processing command line arguments.
[2020-11-22T13:56:11.285534][NOTICE][Options][processCmdLineArgs]rcpath = [None]
[2020-11-22T13:56:11.285564][NOTICE][Options][processCmdLineArgs]dbpath = [None]
[2020-11-22T13:56:11.285580][NOTICE][Options][processCmdLineArgs]logpath = [None]
[2020-11-22T13:56:11.285591][NOTICE][Options][processCmdLineArgs]verbose = [None]
[2020-11-22T13:56:11.285604][NOTICE][Options][processCmdLineArgs]Version = [False]
[2020-11-22T13:56:11.285616][NOTICE][Options][processCmdLineArgs]append = [False]
[2020-11-22T13:56:11.285627][NOTICE][Options][processCmdLineArgs]size = [None]
[2020-11-22T13:56:11.285637][NOTICE][Options][processCmdLineArgs]initdb = [False]
[2020-11-22T13:56:11.285649][NOTICE][Options][processCmdLineArgs]rollback = [None]
[2020-11-22T13:56:11.285660][NOTICE][Options][processCmdLineArgs]rollbackx = [None]
[2020-11-22T13:56:11.285671][NOTICE][Options][processCmdLineArgs]file = [None]
[2020-11-22T13:56:11.285682][NOTICE][Options][processCmdLineArgs]fileattach = [None]
[2020-11-22T13:56:11.285693][NOTICE][Options][processCmdLineArgs]guidedsetup= [False]
[2020-11-22T13:56:11.285704][NOTICE][Options][processCmdLineArgs]noguidedsetup= [False]
[2020-11-22T13:56:11.285715][NOTICE][Options][processCmdLineArgs]nomail = [False]
[2020-11-22T13:56:11.285726][NOTICE][Options][processCmdLineArgs]remove = [None]
[2020-11-22T13:56:11.285737][NOTICE][Options][processCmdLineArgs]purgedb = [False]
[2020-11-22T13:56:11.285748][NOTICE][Options][processCmdLineArgs]stopbackupwarn = [False]
[2020-11-22T13:56:11.285759][NOTICE][Options][processCmdLineArgs]collect = [False]
[2020-11-22T13:56:11.285770][NOTICE][Options][processCmdLineArgs]report = [False]
[2020-11-22T13:56:11.285782][NOTICE][Options][processCmdLineArgs]masksensitive = [False]
[2020-11-22T13:56:11.285793][NOTICE][Options][processCmdLineArgs]nomasksensitive = [False]
[2020-11-22T13:56:11.285804][NOTICE][Options][processCmdLineArgs]validatereport = [False]
[2020-11-22T13:56:11.285815][NOTICE][Options][processCmdLineArgs]layout = [None]
[2020-11-22T13:56:11.285826][NOTICE][Options][processCmdLineArgs]emailservers = [None]
[2020-11-22T13:56:11.285836][NOTICE][Options][processCmdLineArgs]RC path not specified on command line. Using default.
[2020-11-22T13:56:11.285850][NOTICE][Options][processCmdLineArgs]Final RC path=[*********************************]
[2020-11-22T13:56:11.285871][NOTICE][Options][openRcFile]Opening .rc file *********************************
[2020-11-22T13:56:11.286953][NOTICE][Options][checkRcFileVersion]Current version number=310. Need to upgrade rc file? False
[2020-11-22T13:56:11.286984][NOTICE][Options][setRcDefaults]Setting .rc file defaults
[2020-11-22T13:56:11.287087][NOTICE][Options][setRcDefaults]needUpdate = False defaultsOK=True
[2020-11-22T13:56:11.287104][NOTICE][Options][readRcOptions]Reading .rc file options
[2020-11-22T13:56:11.287321][NOTICE][Options][readRcOptions]Need to restart? False
[2020-11-22T13:56:11.287337][NOTICE][Options][initOptions]Option initialization complete. Continuing program.
[2020-11-22T13:56:11.287363][NOTICE][Report][Init]Initializing report object.
[2020-11-22T13:56:11.287379][NOTICE][Options][getRcSection]Retrieving .rc section: [report]
[2020-11-22T13:56:11.287434][NOTICE][Report][validateReportFields]Validating report specifications in .rc file.
[2020-11-22T13:56:11.287449][NOTICE][Report][validateColumns]Validating columns for [report] report section.
[2020-11-22T13:56:11.287522][NOTICE][Options][getRcSection]Retrieving .rc section: [srcdest]
[2020-11-22T13:56:11.287544][NOTICE][Report][validateColumns]Validating columns for [srcdest] report section.
[2020-11-22T13:56:11.287633][NOTICE][Options][getRcSection]Retrieving .rc section: [noactivity]
[2020-11-22T13:56:11.287659][NOTICE][Options][getRcSection]Retrieving .rc section: [lastseen]
[2020-11-22T13:56:11.287683][NOTICE][Report][validateReportFields]Found 0 report validation errors.
[2020-11-22T13:56:11.287699][NOTICE][Report][Init]Getting configuration for ['srcdest'] report.
[2020-11-22T13:56:11.287712][NOTICE][Options][getRcOption]Retrieving .rc option: [srcdest]type=
[2020-11-22T13:56:11.287734][NOTICE][Options][getRcSection]Retrieving .rc section: [srcdest]
[2020-11-22T13:56:11.287814][NOTICE][Report][Init]Getting configuration for ['noactivity'] report.
[2020-11-22T13:56:11.287828][NOTICE][Options][getRcOption]Retrieving .rc option: [noactivity]type=
[2020-11-22T13:56:11.287849][NOTICE][Options][getRcSection]Retrieving .rc section: [noactivity]
[2020-11-22T13:56:11.287939][NOTICE][Report][Init]Getting configuration for ['lastseen'] report.
[2020-11-22T13:56:11.287961][NOTICE][Options][getRcOption]Retrieving .rc option: [lastseen]type=
[2020-11-22T13:56:11.287982][NOTICE][Options][getRcSection]Retrieving .rc section: [lastseen]
[2020-11-22T13:56:11.288005][NOTICE][Report][Init]Adding runtime report.
[2020-11-22T13:56:11.288023][NOTICE][Options][getRcOption]Retrieving .rc option: [apprise]enabled=
[2020-11-22T13:56:11.288043][NOTICE][Database][Init]Initializing database manager.
[2020-11-22T13:56:11.288187][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT major, minor, subminor FROM version WHERE desc = 'data$
[2020-11-22T13:56:11.288454][NOTICE][EmailManager][Init]Initializing Email Manager.
[2020-11-22T13:56:11.288474][NOTICE][EmailManager][validateServerOptions]Validating .rc file options for server incoming
[2020-11-22T13:56:11.288491][NOTICE][Options][getRcSection]Retrieving .rc section: [incoming]
[2020-11-22T13:56:11.288533][NOTICE][EmailManager][validateServerOptions]Validating .rc file options for server outgoing
[2020-11-22T13:56:11.288546][NOTICE][Options][getRcSection]Retrieving .rc section: [outgoing]
[2020-11-22T13:56:11.288596][NOTICE][Database][execSqlStmt]Executing SQL statement: [UPDATE emails SET dbSeen = 0]
[2020-11-22T13:56:11.288693][NOTICE][EmailManager][checkForNewMessages]Checking inbound servers for new email messages.
[2020-11-22T13:56:11.288709][NOTICE][EmailServer][checkForMessages]Checking for messages on server imap.gmail.com. Protocol=imap
[2020-11-22T13:56:11.288722][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T13:56:12.581894][NOTICE][EmailManager][checkForNewMessages]Found 1 new messages on server imap.gmail.com
[2020-11-22T13:56:12.581937][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T13:56:12.581953][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T13:56:12.720543][NOTICE][EmailServer][extractHeaders]Extracting headers from (Date: Sun, 22 Nov 2020 09:35:11 +0000
Subject: Duplicati Success, Backup report for Unraid Backup
Message-Id: <IHUO4GI89CU4.AGQ3BQVAX47F3@dc1324f2e312>
Content-Transfer-Encoding: 7bit

)
[2020-11-22T13:56:12.720645][NOTICE][EmailServer][extractHeaders]Header fields extracted: [{'date': 'Sun, 22 Nov 2020 09:35:11 +0000', 'subject': $
[2020-11-22T13:56:12.720959][NOTICE][EmailServer][processNextMessage]Message [<IHUO4GI89CU4.AGQ3BQVAX47F3@dc1324f2e312>] is not a Message of Inter$
[2020-11-22T13:56:12.720982][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T13:56:12.720996][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T13:56:12.721037][NOTICE][EmailServer][markMessagesRead]Marking 1 imap messages as 'read/seen'
[2020-11-22T13:56:12.976093][NOTICE][Report][extractReportData]Extracting report data.
[2020-11-22T13:56:12.976150][NOTICE][Database][execSqlStmt]Executing SQL statement: [DELETE FROM report]
[2020-11-22T13:56:13.010349][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination, lastTimestamp, lastFileCount, last
[2020-11-22T13:56:13.010504][NOTICE][Report][createReport]Beginning report creation.
[2020-11-22T13:56:13.010597][NOTICE][Report][createReport]Creating report for {'name': 'srcdest', 'type': 'report', 'options': {'layout': [['srcde$
[2020-11-22T13:56:13.010622][NOTICE][Report][buildReportOutputYesGroups]Printing 'grouped' report output.
[2020-11-22T13:56:13.010640][NOTICE][Report][buildReport_Initialize]Building single report: srcdest.
[2020-11-22T13:56:13.010730][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT DISTINCT source , destination  FROM report  ORDER BY s$
[2020-11-22T13:56:13.010816][NOTICE][Report][createReport]Creating report for {'name': 'noactivity', 'type': 'noactivity', 'options': {'layout': '$
[2020-11-22T13:56:13.010845][NOTICE][Report][buildNoActivityOutput]Printing 'No Activity' report output.
[2020-11-22T13:56:13.010874][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT DISTINCT source, destination, lasttimestamp FROM backu$
[2020-11-22T13:56:13.010955][NOTICE][Report][createReport]Creating report for {'name': 'lastseen', 'type': 'lastseen', 'options': {'layout': 'srcd$
[2020-11-22T13:56:13.010975][NOTICE][Report][buildLastSeenOutput]Printing 'Last Seen' report output.
[2020-11-22T13:56:13.011002][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination, dupversion, lastTimestamp FROM ba$
[2020-11-22T13:56:13.011087][NOTICE][Report][createReport]Creating report for {'name': 'runtime', 'type': 'runtime', 'options': {'layout': 'srcdes$
[2020-11-22T13:56:13.011107][NOTICE][Report][buildRuntimeOutput]Calculating running time.
[2020-11-22T13:56:13.011156][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination FROM backupsets ORDER BY source, d$
[2020-11-22T13:56:13.011216][NOTICE][Report][createFormattedOutput]Creating formatted output for html format
[2020-11-22T13:56:13.011234][NOTICE][Report][createHtmlFormat]Creating HTML formatted output.
[2020-11-22T13:56:13.011293][NOTICE][Report][createFormattedOutput]Creating formatted output for txt format
[2020-11-22T13:56:13.011308][NOTICE][Report][createTextFormat]Creating text formatted output.
[2020-11-22T13:56:13.011346][NOTICE][EmailManager][getSmtpServer]Looking for outgoing SMTP server.
[2020-11-22T13:56:13.011370][NOTICE][EmailServer][connect]Connecting to email server 'smtp.gmail.com'
[2020-11-22T13:56:14.228090][NOTICE][EmailServer][connect]Connecting to email server 'smtp.gmail.com'
[2020-11-22T13:56:14.228145][NOTICE][EmailServer][sendEmail]Building email.
[2020-11-22T13:56:14.228624][NOTICE][EmailServer][sendEmail]Sending email to [*]
[2020-11-22T13:56:15.109053][NOTICE][main][Complete]Program completed in 3.825 seconds. Exiting.
[2020-11-22T13:56:15.109113][NOTICE][Globs][closeEverythingAndExit]Closing everything...
[2020-11-22T13:56:15.109131][NOTICE][Globs][closeEverythingAndExit]Closing inbound email server: incoming
[2020-11-22T13:56:15.109146][NOTICE][EmailServer][close]Closing connection to imap.gmail.com.
[2020-11-22T13:56:15.227169][NOTICE][Globs][closeEverythingAndExit]Closing outbound email server: outgoing
[2020-11-22T13:56:15.227221][NOTICE][EmailServer][close]Closing connection to smtp.gmail.com.
[2020-11-22T13:56:15.337759][NOTICE][Globs][closeEverythingAndExit]Closing database file.
[2020-11-22T13:56:15.337808][NOTICE][Database][dbClose]Closing database manager.
[2020-11-22T13:56:15.337914][NOTICE][Globs][closeEverythingAndExit]Closing log file.

HandyGuySoftware commented 3 years ago

OK, I think I see the issue. In the .rc file dupReport is looking for emails with the subject line matching

^Duplicati ([\w ]*, |) Backup report for

(as defined by the subjectregex = parameter in the .rc file) which is the default Duplicati email subject line. However, your emails are coming in with the subject line "Duplicati Success, Backup report for Unraid Backup." This won't match the subjectregex and be discarded, as seen in the log line:

Message [<IHUO4GI89CU4.AGQ3BQVAX47F3@dc1324f2e312>] is not a Message of Interest.

You'll need to either 1) alter the subject line of the outgoing Duplicati emails using the send-mail-subject option in Duplicati, or 2) change the subjectregex= parameter in the .rc file to match what's coming in. Once you get those matched up it should work. If that's the subject line you're going for, some quick tests here show that removing the parentheses and vertical bar from your regex should do the trick, as in

subjectregex = ^Duplicati [\w ]*, Backup report for

Also, you said the backup name is Unraid-Backblaze, but the log file shows the subject as "Duplicati Success, Backup report for Unraid Backup." dupReport won't see a valid backup name in the subject and will fail to parse the message. If you change the send-mail-subject option in Duplicati to include the keyword %backup-name% that should do the trick, as in:

Duplicati %OPERATIONNAME% report for %backup-name%

Hope this all helps. Let me know if you have any more problems.

HG

eldudemeister commented 3 years ago

Thanks for this, so I have amended the .rc file with this subjectregex = ^Duplicati [\w ]*, Backup report for and changed the send-mail-option to Duplicati %OPERATIONNAME% report for %backup-name% but it still doesnt see any emails from duplicati. I'm just using read emails in the duplicati folder as I had configured that in the .rc file. I had actually changed the backup name to `Unraid-Backup' but dupReport doesnt seem to reflect this? Logs below again


[2020-11-22T16:17:08.544232][NOTICE][main][startup]Program Version 3.0.1 Release
[2020-11-22T16:17:08.544248][NOTICE][main][startup]Database Version 3.0.0
[2020-11-22T16:17:08.544259][NOTICE][main][startup]Python version 3.7.3 (default, Jul 25 2020, 13:03:44)
[GCC 8.3.0]
[2020-11-22T16:17:08.544270][NOTICE][main][startup]Program path: /home/matt/dupReport
[2020-11-22T16:17:08.544283][NOTICE][Options][initOptions]Initializing global program options.
[2020-11-22T16:17:08.544295][NOTICE][Options][OptionManager]Initializing option manager.
[2020-11-22T16:17:08.544306][NOTICE][Options][processCmdLineArgs]Processing command line arguments.
[2020-11-22T16:17:08.545597][NOTICE][Options][processCmdLineArgs]rcpath = [None]
[2020-11-22T16:17:08.545626][NOTICE][Options][processCmdLineArgs]dbpath = [None]
[2020-11-22T16:17:08.545652][NOTICE][Options][processCmdLineArgs]logpath = [None]
[2020-11-22T16:17:08.545669][NOTICE][Options][processCmdLineArgs]verbose = [None]
[2020-11-22T16:17:08.545682][NOTICE][Options][processCmdLineArgs]Version = [False]
[2020-11-22T16:17:08.545694][NOTICE][Options][processCmdLineArgs]append = [False]
[2020-11-22T16:17:08.545705][NOTICE][Options][processCmdLineArgs]size = [None]
[2020-11-22T16:17:08.545716][NOTICE][Options][processCmdLineArgs]initdb = [False]
[2020-11-22T16:17:08.545727][NOTICE][Options][processCmdLineArgs]rollback = [None]
[2020-11-22T16:17:08.545738][NOTICE][Options][processCmdLineArgs]rollbackx = [None]
[2020-11-22T16:17:08.545749][NOTICE][Options][processCmdLineArgs]file = [None]
[2020-11-22T16:17:08.545760][NOTICE][Options][processCmdLineArgs]fileattach = [None]
[2020-11-22T16:17:08.545780][NOTICE][Options][processCmdLineArgs]guidedsetup= [False]
[2020-11-22T16:17:08.545793][NOTICE][Options][processCmdLineArgs]noguidedsetup= [False]
[2020-11-22T16:17:08.545804][NOTICE][Options][processCmdLineArgs]nomail = [False]
[2020-11-22T16:17:08.545816][NOTICE][Options][processCmdLineArgs]remove = [None]
[2020-11-22T16:17:08.545826][NOTICE][Options][processCmdLineArgs]purgedb = [False]
[2020-11-22T16:17:08.545837][NOTICE][Options][processCmdLineArgs]stopbackupwarn = [False]
[2020-11-22T16:17:08.545849][NOTICE][Options][processCmdLineArgs]collect = [False]
[2020-11-22T16:17:08.545859][NOTICE][Options][processCmdLineArgs]report = [False]
[2020-11-22T16:17:08.545870][NOTICE][Options][processCmdLineArgs]masksensitive = [False]
[2020-11-22T16:17:08.545881][NOTICE][Options][processCmdLineArgs]nomasksensitive = [False]
[2020-11-22T16:17:08.545892][NOTICE][Options][processCmdLineArgs]validatereport = [False]
[2020-11-22T16:17:08.545903][NOTICE][Options][processCmdLineArgs]layout = [None]
[2020-11-22T16:17:08.545914][NOTICE][Options][processCmdLineArgs]emailservers = [None]
[2020-11-22T16:17:08.545924][NOTICE][Options][processCmdLineArgs]RC path not specified on command line. Using default.
[2020-11-22T16:17:08.545938][NOTICE][Options][processCmdLineArgs]Final RC path=[*********************************]
[2020-11-22T16:17:08.545959][NOTICE][Options][openRcFile]Opening .rc file *********************************
[2020-11-22T16:17:08.547050][NOTICE][Options][checkRcFileVersion]Current version number=310. Need to upgrade rc file? False
[2020-11-22T16:17:08.547071][NOTICE][Options][setRcDefaults]Setting .rc file defaults
[2020-11-22T16:17:08.547154][NOTICE][Options][setRcDefaults]needUpdate = False defaultsOK=True
[2020-11-22T16:17:08.547169][NOTICE][Options][readRcOptions]Reading .rc file options
[2020-11-22T16:17:08.547386][NOTICE][Options][readRcOptions]Need to restart? False
[2020-11-22T16:17:08.547401][NOTICE][Options][initOptions]Option initialization complete. Continuing program.
[2020-11-22T16:17:08.547426][NOTICE][Report][Init]Initializing report object.
[2020-11-22T16:17:08.547442][NOTICE][Options][getRcSection]Retrieving .rc section: [report]
[2020-11-22T16:17:08.547497][NOTICE][Report][validateReportFields]Validating report specifications in .rc file.
[2020-11-22T16:17:08.547511][NOTICE][Report][validateColumns]Validating columns for [report] report section.
[2020-11-22T16:17:08.547579][NOTICE][Options][getRcSection]Retrieving .rc section: [srcdest]
[2020-11-22T16:17:08.547601][NOTICE][Report][validateColumns]Validating columns for [srcdest] report section.
[2020-11-22T16:17:08.547680][NOTICE][Options][getRcSection]Retrieving .rc section: [noactivity]
[2020-11-22T16:17:08.547704][NOTICE][Options][getRcSection]Retrieving .rc section: [lastseen]
[2020-11-22T16:17:08.547729][NOTICE][Report][validateReportFields]Found 0 report validation errors.
[2020-11-22T16:17:08.547744][NOTICE][Report][Init]Getting configuration for ['srcdest'] report.
[2020-11-22T16:17:08.547757][NOTICE][Options][getRcOption]Retrieving .rc option: [srcdest]type=
[2020-11-22T16:17:08.547788][NOTICE][Options][getRcSection]Retrieving .rc section: [srcdest]
[2020-11-22T16:17:08.547871][NOTICE][Report][Init]Getting configuration for ['noactivity'] report.
[2020-11-22T16:17:08.547885][NOTICE][Options][getRcOption]Retrieving .rc option: [noactivity]type=
[2020-11-22T16:17:08.547906][NOTICE][Options][getRcSection]Retrieving .rc section: [noactivity]
[2020-11-22T16:17:08.547995][NOTICE][Report][Init]Getting configuration for ['lastseen'] report.
[2020-11-22T16:17:08.548017][NOTICE][Options][getRcOption]Retrieving .rc option: [lastseen]type=
[2020-11-22T16:17:08.548039][NOTICE][Options][getRcSection]Retrieving .rc section: [lastseen]
[2020-11-22T16:17:08.548062][NOTICE][Report][Init]Adding runtime report.
[2020-11-22T16:17:08.548080][NOTICE][Options][getRcOption]Retrieving .rc option: [apprise]enabled=
[2020-11-22T16:17:08.548101][NOTICE][Database][Init]Initializing database manager.
[2020-11-22T16:17:08.548247][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT major, minor, subminor FROM version WHERE desc = 'data$
[2020-11-22T16:17:08.548530][NOTICE][EmailManager][Init]Initializing Email Manager.
[2020-11-22T16:17:08.548550][NOTICE][EmailManager][validateServerOptions]Validating .rc file options for server incoming
[2020-11-22T16:17:08.548567][NOTICE][Options][getRcSection]Retrieving .rc section: [incoming]
[2020-11-22T16:17:08.548567][NOTICE][Options][getRcSection]Retrieving .rc section: [incoming]
[2020-11-22T16:17:08.548610][NOTICE][EmailManager][validateServerOptions]Validating .rc file options for server outgoing
[2020-11-22T16:17:08.548623][NOTICE][Options][getRcSection]Retrieving .rc section: [outgoing]
[2020-11-22T16:17:08.548663][NOTICE][Database][execSqlStmt]Executing SQL statement: [UPDATE emails SET dbSeen = 0]
[2020-11-22T16:17:08.548756][NOTICE][EmailManager][checkForNewMessages]Checking inbound servers for new email messages.
[2020-11-22T16:17:08.548782][NOTICE][EmailServer][checkForMessages]Checking for messages on server imap.gmail.com. Protocol=imap
[2020-11-22T16:17:08.548796][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T16:17:09.760242][NOTICE][EmailManager][checkForNewMessages]Found 1 new messages on server imap.gmail.com
[2020-11-22T16:17:09.760295][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T16:17:09.760314][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T16:17:09.881192][NOTICE][EmailServer][extractHeaders]Extracting headers from (Date: Sun, 22 Nov 2020 09:35:11 +0000
Subject: Duplicati Success, Backup report for Unraid Backup
Message-Id: <IHUO4GI89CU4.AGQ3BQVAX47F3@dc1324f2e312>
Content-Transfer-Encoding: 7bit

)
[2020-11-22T16:17:09.881291][NOTICE][EmailServer][extractHeaders]Header fields extracted: [{'date': 'Sun, 22 Nov 2020 09:35:11 +0000', 'subject': $
[2020-11-22T16:17:09.881645][NOTICE][EmailServer][processNextMessage]SrcDestDelimeter [-] not found in subject line. Skipping message.
[2020-11-22T16:17:09.881670][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T16:17:09.881684][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T16:17:09.881710][NOTICE][EmailServer][markMessagesRead]Marking 1 imap messages as 'read/seen'
[2020-11-22T16:17:10.002210][NOTICE][Report][extractReportData]Extracting report data.
[2020-11-22T16:17:10.002273][NOTICE][Database][execSqlStmt]Executing SQL statement: [DELETE FROM report]
[2020-11-22T16:17:10.052327][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination, lastTimestamp, lastFileCount, las$
[2020-11-22T16:17:10.052504][NOTICE][Report][createReport]Beginning report creation.
[2020-11-22T16:17:10.052560][NOTICE][Report][createReport]Creating report for {'name': 'srcdest', 'type': 'report', 'options': {'layout': [['srcde$
[2020-11-22T16:17:10.052581][NOTICE][Report][buildReportOutputYesGroups]Printing 'grouped' report output.
[2020-11-22T16:17:10.052597][NOTICE][Report][buildReport_Initialize]Building single report: srcdest.
[2020-11-22T16:17:10.052688][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT DISTINCT source , destination  FROM report  ORDER BY s$
[2020-11-22T16:17:10.052789][NOTICE][Report][createReport]Creating report for {'name': 'noactivity', 'type': 'noactivity', 'options': {'layout': '$
[2020-11-22T16:17:10.052815][NOTICE][Report][buildNoActivityOutput]Printing 'No Activity' report output.
[2020-11-22T16:17:10.052852][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT DISTINCT source, destination, lasttimestamp FROM backu$
[2020-11-22T16:17:10.052949][NOTICE][Report][createReport]Creating report for {'name': 'lastseen', 'type': 'lastseen', 'options': {'layout': 'srcd$
[2020-11-22T16:17:10.052969][NOTICE][Report][buildLastSeenOutput]Printing 'Last Seen' report output.
[2020-11-22T16:17:10.052995][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination, dupversion, lastTimestamp FROM ba$
[2020-11-22T16:17:10.053074][NOTICE][Report][createReport]Creating report for {'name': 'runtime', 'type': 'runtime', 'options': {'layout': 'srcdes$
[2020-11-22T16:17:10.053092][NOTICE][Report][buildRuntimeOutput]Calculating running time.
[2020-11-22T16:17:10.053142][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination FROM backupsets ORDER BY source, d$
[2020-11-22T16:17:10.053202][NOTICE][Report][createFormattedOutput]Creating formatted output for html format
[2020-11-22T16:17:10.053220][NOTICE][Report][createHtmlFormat]Creating HTML formatted output.
[2020-11-22T16:17:10.053277][NOTICE][Report][createFormattedOutput]Creating formatted output for txt format
[2020-11-22T16:17:10.053292][NOTICE][Report][createTextFormat]Creating text formatted output.
[2020-11-22T16:17:10.053335][NOTICE][EmailManager][getSmtpServer]Looking for outgoing SMTP server.
[2020-11-22T16:17:10.053353][NOTICE][EmailServer][connect]Connecting to email server 'smtp.gmail.com'
[2020-11-22T16:17:11.253837][NOTICE][EmailServer][connect]Connecting to email server 'smtp.gmail.com'
[2020-11-22T16:17:11.253892][NOTICE][EmailServer][sendEmail]Building email.
[2020-11-22T16:17:11.254313][NOTICE][EmailServer][sendEmail]Sending email to [*]
[2020-11-22T16:17:12.065616][NOTICE][main][Complete]Program completed in 3.521 seconds. Exiting.
[2020-11-22T16:17:12.065680][NOTICE][Globs][closeEverythingAndExit]Closing everything...
[2020-11-22T16:17:12.065700][NOTICE][Globs][closeEverythingAndExit]Closing inbound email server: incoming
[2020-11-22T16:17:12.065718][NOTICE][EmailServer][close]Closing connection to imap.gmail.com.
[2020-11-22T16:17:12.183013][NOTICE][Globs][closeEverythingAndExit]Closing outbound email server: outgoing
[2020-11-22T16:17:12.183071][NOTICE][EmailServer][close]Closing connection to smtp.gmail.com.
[2020-11-22T16:17:12.290483][NOTICE][Globs][closeEverythingAndExit]Closing database file.
[2020-11-22T16:17:12.290542][NOTICE][Database][dbClose]Closing database manager.
[2020-11-22T16:17:12.290678][NOTICE][Globs][closeEverythingAndExit]Closing log file.````

HandyGuySoftware commented 3 years ago

Try this:

Re-run Duplicati to force it to run another backup and send another result email.
Once the backup is complete, check your email folder to make sure the result email came through with the proper subject line.
Run dupReport with the -i option. This will clear out the database before starting, so everything looks new.

See if that makes any difference.

eldudemeister commented 3 years ago

Awesome I think that's sorted it, thank you! I did also change the folder back to my inbox, not sure if that's related. Anyway at least I know it's working now so I can try changing the folder back and adding in apprise notifications :) thanks again.

HandyGuySoftware commented 3 years ago

Happy to help. :-)

eldudemeister commented 3 years ago

Sorry to comment back but I am having issues again, the logs are showing (i think) the emails from duplicati but dupreport isnt picking them up. Have tried rerunning the backup and then the -i command on dupreport....any advice would be great please. Also apprise doesnt seem to be sending the notifications as part of dupReport although I can manaully send using the command line for apprise. Wondering if it is linked?


[2020-11-22T20:12:10.597378][NOTICE][main][startup]Program Version 3.0.1 Release
[2020-11-22T20:12:10.597393][NOTICE][main][startup]Database Version 3.0.0
[2020-11-22T20:12:10.597405][NOTICE][main][startup]Python version 3.7.3 (default, Jul 25 2020, 13:03:44)
[GCC 8.3.0]
[2020-11-22T20:12:10.597415][NOTICE][main][startup]Program path: /home/matt/dupReport
[2020-11-22T20:12:10.597428][NOTICE][Options][initOptions]Initializing global program options.
[2020-11-22T20:12:10.597440][NOTICE][Options][OptionManager]Initializing option manager.
[2020-11-22T20:12:10.597451][NOTICE][Options][processCmdLineArgs]Processing command line arguments.
[2020-11-22T20:12:10.598828][NOTICE][Options][processCmdLineArgs]rcpath = [None]
[2020-11-22T20:12:10.598850][NOTICE][Options][processCmdLineArgs]dbpath = [None]
[2020-11-22T20:12:10.598863][NOTICE][Options][processCmdLineArgs]logpath = [None]
[2020-11-22T20:12:10.598875][NOTICE][Options][processCmdLineArgs]verbose = [None]
[2020-11-22T20:12:10.598888][NOTICE][Options][processCmdLineArgs]Version = [False]
[2020-11-22T20:12:10.598899][NOTICE][Options][processCmdLineArgs]append = [False]
[2020-11-22T20:12:10.598910][NOTICE][Options][processCmdLineArgs]size = [None]
[2020-11-22T20:12:10.598922][NOTICE][Options][processCmdLineArgs]initdb = [True]
[2020-11-22T20:12:10.598933][NOTICE][Options][processCmdLineArgs]rollback = [None]
[2020-11-22T20:12:10.598944][NOTICE][Options][processCmdLineArgs]rollbackx = [None]
[2020-11-22T20:12:10.598955][NOTICE][Options][processCmdLineArgs]file = [None]
[2020-11-22T20:12:10.598966][NOTICE][Options][processCmdLineArgs]fileattach = [None]
[2020-11-22T20:12:10.598977][NOTICE][Options][processCmdLineArgs]guidedsetup= [False]
[2020-11-22T20:12:10.598988][NOTICE][Options][processCmdLineArgs]noguidedsetup= [False]
[2020-11-22T20:12:10.598999][NOTICE][Options][processCmdLineArgs]nomail = [False]
[2020-11-22T20:12:10.599010][NOTICE][Options][processCmdLineArgs]remove = [None]
[2020-11-22T20:12:10.599021][NOTICE][Options][processCmdLineArgs]purgedb = [False]
[2020-11-22T20:12:10.599032][NOTICE][Options][processCmdLineArgs]stopbackupwarn = [False]
[2020-11-22T20:12:10.599043][NOTICE][Options][processCmdLineArgs]collect = [False]
[2020-11-22T20:12:10.599054][NOTICE][Options][processCmdLineArgs]report = [False]
[2020-11-22T20:12:10.599075][NOTICE][Options][processCmdLineArgs]masksensitive = [False]
[2020-11-22T20:12:10.599087][NOTICE][Options][processCmdLineArgs]nomasksensitive = [False]
[2020-11-22T20:12:10.599099][NOTICE][Options][processCmdLineArgs]validatereport = [False]
[2020-11-22T20:12:10.599110][NOTICE][Options][processCmdLineArgs]layout = [None]
[2020-11-22T20:12:10.599121][NOTICE][Options][processCmdLineArgs]emailservers = [None]
[2020-11-22T20:12:10.599131][NOTICE][Options][processCmdLineArgs]RC path not specified on command line. Using default.
[2020-11-22T20:12:10.599145][NOTICE][Options][processCmdLineArgs]Final RC path=[*********************************]
[2020-11-22T20:12:10.599159][NOTICE][Options][openRcFile]Opening .rc file *********************************
[2020-11-22T20:12:10.600197][NOTICE][Options][checkRcFileVersion]Current version number=310. Need to upgrade rc file? False
[2020-11-22T20:12:10.600214][NOTICE][Options][setRcDefaults]Setting .rc file defaults
[2020-11-22T20:12:10.600297][NOTICE][Options][setRcDefaults]needUpdate = False defaultsOK=True
[2020-11-22T20:12:10.600311][NOTICE][Options][readRcOptions]Reading .rc file options
[2020-11-22T20:12:10.600523][NOTICE][Options][readRcOptions]Need to restart? False
[2020-11-22T20:12:10.600537][NOTICE][Options][initOptions]Option initialization complete. Continuing program.
[2020-11-22T20:12:10.600562][NOTICE][Report][Init]Initializing report object.
[2020-11-22T20:12:10.600578][NOTICE][Options][getRcSection]Retrieving .rc section: [report]
[2020-11-22T20:12:10.600633][NOTICE][Report][validateReportFields]Validating report specifications in .rc file.
[2020-11-22T20:12:10.600647][NOTICE][Report][validateColumns]Validating columns for [report] report section.
[2020-11-22T20:12:10.600718][NOTICE][Options][getRcSection]Retrieving .rc section: [srcdest]
[2020-11-22T20:12:10.600740][NOTICE][Report][validateColumns]Validating columns for [srcdest] report section.
[2020-11-22T20:12:10.600817][NOTICE][Options][getRcSection]Retrieving .rc section: [noactivity]
[2020-11-22T20:12:10.600842][NOTICE][Options][getRcSection]Retrieving .rc section: [lastseen]
[2020-11-22T20:12:10.600866][NOTICE][Report][validateReportFields]Found 0 report validation errors.
[2020-11-22T20:12:10.600881][NOTICE][Report][Init]Getting configuration for ['srcdest'] report.
[2020-11-22T20:12:10.600894][NOTICE][Options][getRcOption]Retrieving .rc option: [srcdest]type=
[2020-11-22T20:12:10.600915][NOTICE][Options][getRcSection]Retrieving .rc section: [srcdest]
[2020-11-22T20:12:10.600995][NOTICE][Report][Init]Getting configuration for ['noactivity'] report.
[2020-11-22T20:12:10.601008][NOTICE][Options][getRcOption]Retrieving .rc option: [noactivity]type=
[2020-11-22T20:12:10.601029][NOTICE][Options][getRcSection]Retrieving .rc section: [noactivity]
[2020-11-22T20:12:10.601126][NOTICE][Report][Init]Getting configuration for ['lastseen'] report.
[2020-11-22T20:12:10.601144][NOTICE][Options][getRcOption]Retrieving .rc option: [lastseen]type=
[2020-11-22T20:12:10.601165][NOTICE][Options][getRcSection]Retrieving .rc section: [lastseen]
[2020-11-22T20:12:10.601192][NOTICE][Report][Init]Adding runtime report.
[2020-11-22T20:12:10.601210][NOTICE][Options][getRcOption]Retrieving .rc option: [apprise]enabled=
[2020-11-22T20:12:10.601230][NOTICE][Apprise][Init]Initializing Apprise support
[2020-11-22T20:12:10.772197][NOTICE][Options][getRcSection]Retrieving .rc section: [apprise]
[2020-11-22T20:12:10.772623][NOTICE][Apprise][Init]Initializing Apprise library. Result=<apprise.Apprise.Apprise object at 0x7f06b8a76710>
[2020-11-22T20:12:10.773920][NOTICE][Apprise][Init]Added service json://192.168.68.132:8123/api/webhook/AaQSrZoiCPcR8c3gcjSb5pP4Y8VfNERO, result=T$
[2020-11-22T20:12:10.773955][NOTICE][Apprise][Init]Apprise Initialization complete.
[2020-11-22T20:12:10.773985][NOTICE][Database][Init]Initializing database manager.
[2020-11-22T20:12:10.774177][NOTICE][main][InitDB]Database initialization specified on command line.
[2020-11-22T20:12:10.774200][NOTICE][Database][dbInitialize]Initializing (resetting) database.
[2020-11-22T20:12:10.774219][NOTICE][Database][execSqlStmt]Executing SQL statement: [drop table if exists version]
[2020-11-22T20:12:10.822444][NOTICE][Database][execSqlStmt]Executing SQL statement: [drop table if exists emails]
[2020-11-22T20:12:10.851418][NOTICE][Database][execSqlStmt]Executing SQL statement: [drop table if exists backupsets]
[2020-11-22T20:12:10.880694][NOTICE][Database][execSqlStmt]Executing SQL statement: [drop table if exists report]
[2020-11-22T20:12:10.908294][NOTICE][Database][execSqlStmt]Executing SQL statement: [drop index if exists emailindx]
[2020-11-22T20:12:10.908416][NOTICE][Database][execSqlStmt]Executing SQL statement: [drop index if exists srcdestindx]
[2020-11-22T20:12:10.908468][NOTICE][Database][execSqlStmt]Executing SQL statement: [create table version (desc varchar(20), major int, minor int,$
[2020-11-22T20:12:10.939422][NOTICE][Database][execSqlStmt]Executing SQL statement: [insert into version(desc, major, minor, subminor) values ('da$
[2020-11-22T20:12:10.939774][NOTICE][Database][execSqlStmt]Executing SQL statement: [create table emails (messageId varchar(50), sourceComp varcha$
[2020-11-22T20:12:10.941091][NOTICE][Database][execSqlStmt]Executing SQL statement: [create index emailindx on emails (messageId)]
[2020-11-22T20:12:10.941227][NOTICE][Database][execSqlStmt]Executing SQL statement: [create index srcdestindx on emails (sourceComp, destComp)]
[2020-11-22T20:12:10.941326][NOTICE][Database][execSqlStmt]Executing SQL statement: [create table report (source varchar(20), destination varchar($
[2020-11-22T20:12:10.941428][NOTICE][Database][execSqlStmt]Executing SQL statement: [create table backupsets (source varchar(20), destination varc$
[2020-11-22T20:12:10.970482][NOTICE][Database][dbCompact]Compacting database
[2020-11-22T20:12:10.970532][NOTICE][Database][execSqlStmt]Executing SQL statement: [VACUUM]
[2020-11-22T20:12:11.006282][NOTICE][Database][dbCompact]Database compaction complete.
[2020-11-22T20:12:11.006309][NOTICE][Database][dbInitialize]Database initialization complete.
[2020-11-22T20:12:11.006330][NOTICE][EmailManager][Init]Initializing Email Manager.
[2020-11-22T20:12:11.006355][NOTICE][EmailManager][validateServerOptions]Validating .rc file options for server incoming
[2020-11-22T20:12:11.006372][NOTICE][Options][getRcSection]Retrieving .rc section: [incoming]
[2020-11-22T20:12:11.006444][NOTICE][EmailManager][validateServerOptions]Validating .rc file options for server outgoing
[2020-11-22T20:12:11.006458][NOTICE][Options][getRcSection]Retrieving .rc section: [outgoing]
[2020-11-22T20:12:11.006515][NOTICE][Database][execSqlStmt]Executing SQL statement: [UPDATE emails SET dbSeen = 0]
[2020-11-22T20:12:11.006785][NOTICE][EmailManager][checkForNewMessages]Checking inbound servers for new email messages.
[2020-11-22T20:12:11.006806][NOTICE][EmailServer][checkForMessages]Checking for messages on server imap.gmail.com. Protocol=imap
[2020-11-22T20:12:11.006820][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T20:12:12.301492][NOTICE][EmailManager][checkForNewMessages]Found 4 new messages on server imap.gmail.com
[2020-11-22T20:12:12.301539][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T20:12:12.301557][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T20:12:12.438749][NOTICE][EmailServer][extractHeaders]Extracting headers from (Date: Sun, 22 Nov 2020 09:35:11 +0000
Subject: Duplicati Success, Backup report for Unraid Backup
Message-Id: <IHUO4GI89CU4.AGQ3BQVAX47F3@dc1324f2e312>
Content-Transfer-Encoding: 7bit

)
[2020-11-22T20:12:12.438806][NOTICE][EmailServer][extractHeaders]Header fields extracted: [{'date': 'Sun, 22 Nov 2020 09:35:11 +0000', 'subject': $
[2020-11-22T20:12:12.439182][NOTICE][EmailServer][processNextMessage]SrcDestDelimeter [-] not found in subject line. Skipping message.
[2020-11-22T20:12:12.439206][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T20:12:12.439220][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T20:12:12.563220][NOTICE][EmailServer][extractHeaders]Extracting headers from (Date: Sun, 22 Nov 2020 16:58:44 +0000
Subject: Duplicati Backup report for Unraid-Backblaze
Message-Id: <IN7TKPWB9CU4.C2DDZDBO4II71@dc1324f2e312>
Content-Transfer-Encoding: 7bit

)
[2020-11-22T20:12:12.563309][NOTICE][EmailServer][extractHeaders]Header fields extracted: [{'date': 'Sun, 22 Nov 2020 16:58:44 +0000', 'subject': $
[2020-11-22T20:12:12.563356][NOTICE][EmailServer][processNextMessage]Message [<IN7TKPWB9CU4.C2DDZDBO4II71@dc1324f2e312>] is not a Message of Inter$
[2020-11-22T20:12:12.563377][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T20:12:12.563390][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T20:12:12.687511][NOTICE][EmailServer][extractHeaders]Extracting headers from (Date: Sun, 22 Nov 2020 19:29:58 +0000
Subject: Duplicati Backup report for Unraid-Backblaze
Message-Id: <Q6B26E2D9CU4.32HCGZUKJF0Z1@dc1324f2e312>
Content-Transfer-Encoding: 7bit

)
[2020-11-22T20:12:12.687564][NOTICE][EmailServer][extractHeaders]Header fields extracted: [{'date': 'Sun, 22 Nov 2020 19:29:58 +0000', 'subject': $
[2020-11-22T20:12:12.687603][NOTICE][EmailServer][processNextMessage]Message [<Q6B26E2D9CU4.32HCGZUKJF0Z1@dc1324f2e312>] is not a Message of Inter$
[2020-11-22T20:12:12.687622][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T20:12:12.687635][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T20:12:12.811430][NOTICE][EmailServer][extractHeaders]Extracting headers from (Date: Sun, 22 Nov 2020 18:00:28 +0000
Subject: Duplicati Backup report for Unraid-Backblaze
Message-Id: <KTOB5QDC9CU4.PNITO63R1WTC3@dc1324f2e312>
Content-Transfer-Encoding: 7bit
[2020-11-22T20:12:12.811484][NOTICE][EmailServer][extractHeaders]Header fields extracted: [{'date': 'Sun, 22 Nov 2020 18:00:28 +0000', 'subject': $
[2020-11-22T20:12:12.811524][NOTICE][EmailServer][processNextMessage]Message [<KTOB5QDC9CU4.PNITO63R1WTC3@dc1324f2e312>] is not a Message of Inter$
[2020-11-22T20:12:12.811543][NOTICE][EmailServer][processNextMessage]Processing next message on server imap.gmail.com. Protocol=imap
[2020-11-22T20:12:12.811557][NOTICE][EmailServer][connect]Connecting to email server 'imap.gmail.com'
[2020-11-22T20:12:12.811585][NOTICE][EmailServer][markMessagesRead]Marking 4 imap messages as 'read/seen'
[2020-11-22T20:12:13.454439][NOTICE][Report][extractReportData]Extracting report data.
[2020-11-22T20:12:13.454501][NOTICE][Database][execSqlStmt]Executing SQL statement: [DELETE FROM report]
[2020-11-22T20:12:13.484827][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination, lastTimestamp, lastFileCount, las$
[2020-11-22T20:12:13.484974][NOTICE][Report][createReport]Beginning report creation.
[2020-11-22T20:12:13.485031][NOTICE][Report][createReport]Creating report for {'name': 'srcdest', 'type': 'report', 'options': {'layout': [['srcde$
[2020-11-22T20:12:13.485099][NOTICE][Report][buildReportOutputYesGroups]Printing 'grouped' report output.
[2020-11-22T20:12:13.485120][NOTICE][Report][buildReport_Initialize]Building single report: srcdest.
[2020-11-22T20:12:13.485209][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT DISTINCT source , destination  FROM report  ORDER BY s$
[2020-11-22T20:12:13.485302][NOTICE][Report][createReport]Creating report for {'name': 'noactivity', 'type': 'noactivity', 'options': {'layout': '$
[2020-11-22T20:12:13.485323][NOTICE][Report][buildNoActivityOutput]Printing 'No Activity' report output.
[2020-11-22T20:12:13.485351][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT DISTINCT source, destination, lasttimestamp FROM backu$
[2020-11-22T20:12:13.485470][NOTICE][Report][createReport]Creating report for {'name': 'lastseen', 'type': 'lastseen', 'options': {'layout': 'srcd$
[2020-11-22T20:12:13.485497][NOTICE][Report][buildLastSeenOutput]Printing 'Last Seen' report output.
[2020-11-22T20:12:13.485525][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination, dupversion, lastTimestamp FROM ba$
[2020-11-22T20:12:13.485612][NOTICE][Report][createReport]Creating report for {'name': 'runtime', 'type': 'runtime', 'options': {'layout': 'srcdes$
[2020-11-22T20:12:13.485630][NOTICE][Report][buildRuntimeOutput]Calculating running time.
[2020-11-22T20:12:13.485682][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination FROM backupsets ORDER BY source, d$
[2020-11-22T20:12:13.485741][NOTICE][Database][execSqlStmt]Executing SQL statement: [SELECT source, destination, parsedResult, messages, warnings,$
[2020-11-22T20:12:13.485809][NOTICE][Report][createFormattedOutput]Creating formatted output for html format
[2020-11-22T20:12:13.485831][NOTICE][Report][createHtmlFormat]Creating HTML formatted output.
[2020-11-22T20:12:13.485890][NOTICE][Report][createFormattedOutput]Creating formatted output for txt format
[2020-11-22T20:12:13.485905][NOTICE][Report][createTextFormat]Creating text formatted output.
[2020-11-22T20:12:13.485940][NOTICE][EmailManager][getSmtpServer]Looking for outgoing SMTP server.
[2020-11-22T20:12:13.485957][NOTICE][EmailServer][connect]Connecting to email server 'smtp.gmail.com'
[2020-11-22T20:12:14.692337][NOTICE][EmailServer][connect]Connecting to email server 'smtp.gmail.com'
[2020-11-22T20:12:14.692416][NOTICE][EmailServer][sendEmail]Building email.
[2020-11-22T20:12:14.692804][NOTICE][EmailServer][sendEmail]Sending email to [*]
[2020-11-22T20:12:15.535536][NOTICE][main][Complete]Program completed in 4.938 seconds. Exiting.
[2020-11-22T20:12:15.535598][NOTICE][Globs][closeEverythingAndExit]Closing everything...
[2020-11-22T20:12:15.535615][NOTICE][Globs][closeEverythingAndExit]Closing inbound email server: incoming
[2020-11-22T20:12:15.535631][NOTICE][EmailServer][close]Closing connection to imap.gmail.com.
[2020-11-22T20:12:15.656649][NOTICE][Globs][closeEverythingAndExit]Closing outbound email server: outgoing
[2020-11-22T20:12:15.656697][NOTICE][EmailServer][close]Closing connection to smtp.gmail.com.
[2020-11-22T20:12:15.759587][NOTICE][Globs][closeEverythingAndExit]Closing database file.
[2020-11-22T20:12:15.759684][NOTICE][Database][dbClose]Closing database manager.
[2020-11-22T20:12:15.759826][NOTICE][Globs][closeEverythingAndExit]Closing log file.```

HandyGuySoftware commented 3 years ago

Can you put the log file and the current .rc file up on pastebin (or some other file location)? GitHub keeps truncating the lines and I can't see the full debug output.

From the looks of it, the program is failing on matching the subjectregex with the subject line in the email. That's how the "is not a Message of Interest" message gets generated. A look at the full log & .rc will confirm that.

eldudemeister commented 3 years ago

Sure, https://pastebin.pl/view/88eadcd6 is the .rc and https://pastebin.pl/view/dd97852a is the logs. Thanks for looking, not sure what I have done here.

HandyGuySoftware commented 3 years ago

The regex is still mismatched. Try:

subjectregex = ^Duplicati Backup report for

That will match the subject lines you're getting:

Subject: Duplicati Backup report for Unraid-Backblaze

If you still want to include the backup type indicator, there is an extra comma and space in your regex. Try:

subjectregex = ^Duplicati [\w ]*Backup report for

Also, try a higher debug level for a while:

verbose = 7

That may give you some more useful information as you work through this.

eldudemeister commented 3 years ago

Thanks! Got it! In terms of running it going forward, I'm not sure which flag to set when I run the command? Ideally I'd just have it check once a week if that can be set as that's when I'll be doing backups?

HandyGuySoftware commented 3 years ago

Good to hear. You shouldn't need any command line flags on a regular basis. The only one you might consider is the -f flag to send the output to a file as well as the email. This can sometimes be useful if you lose an email or want a permanent record of the run. Otherwise, the default options should be fine.

As for scheduling runs, dupReport doesn't have a built-in scheduler, but you can use your operating system's scheduler to do the trick (cron on Linux, Task Scheduler on Windows). Just make sure that you leave enough time for your backup to complete before running dupReport. Duplicati isn't always the fastest backup program around, so if you're doing backups weekly there might be lots of changes to back up. Take a look at the running times of your recent backups, then pad those a bit to come up with the best time to run dupReport.

eldudemeister commented 3 years ago

Great thanks, really appreciate all the help! Is this the best way to ask any further queries if they come up or should I do that on the forum?

HandyGuySoftware commented 3 years ago

You can ask general questions on the Duplicati Forum. Problems, crashes, or new feature requests should be done here on GitHub.

HandyGuySoftware / dupReport

dupReport not picking up emails from Duplicati. #159