2.1 Beta no go

[handyguysoftware]

2.1 Beta no go

[HandyGuySoftware]

Happened to be in the code tracking down a bug for mr-flibble and saw your come it. Yours was an easy fix. Download and try again.

[dcurrey]

Should this issue be closed? I am still getting it clean setup.

Did figure out it tied to the creation of the .rc file. If I create a dupReport.rc file with just

[main]
version = 2.1.0

It will go ahead and create the full file.
It will also upgrade the 2.0.3 rc file. This is how I got passed the issue for testing.

Refuses to create the file from scratch.

[HandyGuySoftware]

See, this is what happens when you take working code and try to fancy it up ;-) Should be fixed now. Missing .rc file should not stop the program. Pushed new beta out. See if that works.

[dcurrey]

Almost, now I get
Invalid RC file size display option in [report] section: sizedisplay cannot be 'none'

Changed the options.py to set sizedisplay to bytes to match the showsizedisplay default.

For some reason when I tested it on my live server I got the following at top of report table.
< td align="right"> +0

The table the displayed correctly with a couple of entries not in centered. I will watch this now that I have some actual live data to work with.

Another minor bug is in the db.py Line 118. Looks like you have "parsedResult int" in the create table reports sql statement. Should that be "parsedResult varchar(30)"? You would think sqlite would freak out on that since the parsedResult is a string.

[HandyGuySoftware]

OK. The first one is a result of my changing the 'size display' settings after the conversion routine was already written and not checking back that they were in sync. An easy fix.

The table definition is puzzling but also an easy fix.

As for the table display, which report were you running when you saw this? That will help me track down the culprit. Most likely a missing HTML closing tag somewhere. I'm making some changes to streamline some of the table definition and creation, so that should help fix that as well.

Thanks for all the testing. I really appreciate the help!

[dcurrey]

I looks like its the srcdest report.

Just did a new run to see what an updated report looks like and date goes half way across the table. Its only had one change since the initial run that has 144 emails in it.

[HandyGuySoftware]

Can you upload a screenshot of the errant headers?

[dcurrey]

Here I think this was the srcdest

This came from bydest

[HandyGuySoftware]

Had a hard time trying to trace this because nothing in the code seemed to be able to produce this pattern. I can't find anywhere that opens a <td...> and closes a without also closing a . Frustrating.

Made some fixes to optimize the the report generation which might also fix this. Have a go at it and see what happens.

[dcurrey]

Tried clean run again. Tables still have issues.

The "sizedisplay = none" is still in the dupReport.rc on clean install.

Only options changed was the inbound/outbound server settings fixed the sizieofdisplay to bytes and change "srcdestdelimiter = @"

[HandyGuySoftware]

Clearly I'm missing something. A couple of questions:

1. When you say "clean install" are you starting with no .rc or .db file?
2. It looks like the srcdestdelim is working OK, but the size is not displaying as bytes. Is that correct?
3. Have you tried using the -i option, to clean out the DB before processing? (Depends o the answer to #1.)

I'll take another look at it tonight. Sorry 'bout that.

[dcurrey]

1, Correct. I unzip the file and run everything inside the directory. The .rc .tmp .log .db files all are being created and used here.

2. srcdestdelim is working correctly I just have the "@" as the delimiter instead of "-"
   The problem was the sizedisplay is being set to none by default. This creates an error

Invalid RC file size display option in [report] section: sizedisplay cannot be 'none'

Fix was above.
3. Always use the -i option when testing and resetting the report.

[dcurrey]

Ok seems it may be some bad duplicati emails if I remove them the report runs correctly

Email1

DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 12
OpenedFiles: 5
AddedFiles: 5
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 6886293
SizeOfExaminedFiles: 6935285
SizeOfOpenedFiles: 6886293
NotProcessedFiles: 0
AddedFolders: 2
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
ParsedResult: Success
VerboseOutput: False
VerboseErrors: False
EndTime: 11/3/2017 5:40:11 PM
BeginTime: 11/3/2017 5:40:09 PM
Duration: 00:00:01.5858280
Messages: [
      No remote filesets were deleted,
      Compacting not required
]
Warnings: [This is some warning message!!!]
Errors: []

email2

DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 12
OpenedFiles: 0
AddedFiles: 0
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 0
SizeOfExaminedFiles: 6935285
SizeOfOpenedFiles: 0
NotProcessedFiles: 0
AddedFolders: 0
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
ParsedResult: Success
VerboseOutput: False
VerboseErrors: False
EndTime: 11/2/2017 6:06:39 PM
BeginTime: 11/2/2017 6:06:39 PM
Duration: 00:00:00.8053400
Messages: [
    No remote filesets were deleted,
    removing file listed as Temporary: duplicati-b5290ce09121f4ed58e2c25d48424bb8a.dblock.zip,
    removing file listed as Temporary: duplicati-i0567897869bb497eaa4aafb471272089.dindex.zip
]
Warnings: []
Errors: []

[HandyGuySoftware]

If you run the logs at level 3 (-v3) with the bad emails in the mix do they tell you anything interesting that might point to a clue?

[dcurrey]

Well crap no luck.

Verbose log didn't really show anything. Well is showed a ton of stuff but nothing stood out as wrong.

looking at the raw data in database nothing stands out as wrong with any of the tables.

looking at the plain version of email doesn't show the errors.

It appears to be some strange combination of emails. Put one of the bad emails alone in folder ran dupreport -i and it worked. Added one at at time until it screwed up again. Was starting to think it was file +0 had something to do with it but can't confirm it nor reproduce it with different data sets.

Even tried moving all my production server emails into it different folder just leaving this month only and still getting almost random errors. At one point just the work Source ended up being displaying as "Sour ce" in section title.

Am I the only one having this problem????

[dcurrey]

Ok I see what is happening, I just don't know why or how to fix it.

Here is what I am seeing.
In the dremail.py file section def sendEmail(self, msgHtml, msgText = None):
I added "print(msgHtml)
just before the self.server.sendmail(globs.opts['outsender'], globs.opts['outreceiver'], msg.as_string().encode('utf-8')) line
ran dupreport -i

pasted the results of the print message into a blank website.

Ok that looks right.

But the email still shows

Not so good.

Here is the webpage date. First section is the output of print statement second is the source data from the email.

<html><head></head><body><table border=1 cellpadding="5"><tr><td align="center" colspan="13" bgcolor="#FFFFFF"><b>Duplicati Backup Summary Report</b></td></tr><tr><td align="left">Date</td><td align="left">Time</td><td align="right">Files</td><td align="right">+/-</td><td align="right">Size</td><td align="right">+/-</td><td align="right">Added</td><td align="right">Deleted</td><td align="right">Modified</td><td align="right">Errors</td><td align="left">Result</td></tr><tr><td colspan="13" align="center" bgcolor="#D3D3D3"><b>Source:</b> backup <b>Destination:</b> ddc3</td></tr><tr><td align="left">11/02/2017</td><td align="left">17:38:10</td><td align="right">           7</td><td align="right">          +7</td><td align="right">              48,992</td><td align="right">             +48,992</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">11/02/2017</td><td align="left">17:40:11</td><td align="right">          12</td><td align="right">          +5</td><td align="right">           6,935,285</td><td align="right">          +6,886,293</td><td align="right">           5</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">11/02/2017</td><td align="left">18:06:39</td><td align="right">          12</td><td align="right">          +0</td><td align="right">           6,935,285</td><td align="right">                  +0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">11/22/2017</td><td align="left">13:59:19</td><td align="right">          56</td><td align="right">         +44</td><td align="right">          30,166,651</td><td align="right">         +23,231,366</td><td align="right">          44</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">12/12/2017</td><td align="left">16:02:30</td><td align="right">          50</td><td align="right">          -6</td><td align="right">             606,609</td><td align="right">         -29,560,042</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">12/12/2017</td><td align="left">16:20:47</td><td align="right">          50</td><td align="right">          +0</td><td align="right">             606,609</td><td align="right">                  +0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">12/12/2017</td><td align="left">16:22:53</td><td align="right">          50</td><td align="right">          +0</td><td align="right">             606,624</td><td align="right">                 +15</td><td align="right">           0</td><td align="right">           0</td><td align="right">           1</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td colspan=13 align="center"><b>Running Time: 0.233 seconds.</b></td></tr></table></body></html>




<html><head></head><body><table border=1 cellpadding="5"><tr><td align="center" colspan="13" bgcolor="#FFFFFF"><b>Duplicati Backup Summary Report</b></td></tr><tr><td align="left">Date</td><td align="left">Time</td><td align="right">Files</td><td align="right">+/-</td><td align="right">Size</td><td align="right">+/-</td><td align="right">Added</td><td align="right">Deleted</td><td align="right">Modified</td><td align="right">Errors</td><td align="left">Result</td></tr><tr><td colspan="13" align="center" bgcolor="#D3D3D3"><b>Source:</b> backup <b>Destination:</b> ddc3</td></tr><tr><td align="left">11/02/2017</td><td align="left">17:38:10</td><td align="right">           7</td><td align="right">          +7</td><td align="right">              48,992</td><td align="right">             +48,992</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left
 ">11/02/2017</td><td align="left">17:40:11</td><td align="right">          12</td><td align="right">          +5</td><td align="right">           6,935,285</td><td align="right">          +6,886,293</td><td align="right">           5</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">11/02/2017</td><td align="left">18:06:39</td><td align="right">          12</td><td align="right">          +0</td><td align="right">           6,935,285</td><td align="right">                  +0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">11/22/2017</td><td align="left">13:59:19</td><td align="right">          56</td><td align="right">         +44</td><td align="right">          30,166,651</td><td align="right">         +23,231,366</td><t
 d align="right">          44</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">12/12/2017</td><td align="left">16:02:30</td><td align="right">          50</td><td align="right">          -6</td><td align="right">             606,609</td><td align="right">         -29,560,042</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">12/12/2017</td><td align="left">16:20:47</td><td align="right">          50</td><td align="right">          +0</td><td align="right">             606,609</td><td align="right">                  +0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td align="left">12/12/2017</
 td><td align="left">16:22:53</td><td align="right">          50</td><td align="right">          +0</td><td align="right">             606,624</td><td align="right">                 +15</td><td align="right">           0</td><td align="right">           0</td><td align="right">           1</td><td align="right">           0</td><td align="left">Success</td></tr><tr><td colspan=13 align="center"><b>Running Time: 0.233 seconds.</b></td></tr></table></body></html>

[HandyGuySoftware]

Tracing the two outputs now, but I have a theory. Just for giggles, change the self.server.sendmail(.... line from

self.server.sendmail(globs.opts['outsender'], globs.opts['outreceiver'], msg.as_string().encode('utf-8'))
to
self.server.sendmail(globs.opts['outsender'], globs.opts['outreceiver'], msg.as_string())

i.e., remove the "encode('utf-8')" bit. I have a hunch I know what's happening, but this will confirm it. Or not.

FYI, you can also now use the -f option to send the output to a file. If you tell it to output HTML format it will send the contents of the msgHtml variable directly to a file. That'll save you the step of having to print it and copy the output to a file.

Let me know if that change fixes anything.

[HandyGuySoftware]

Also, while you're at it, use the -f option to also send the data to a text file. You can use more than one -f option at a time. See if the text file looks ok. Another data point.

[dcurrey]

Tried the -f test3.html,html and copied the file over to my webserver. Everything is as it should.

Didn't think to use the -f option also. Nice.

Already tried removing the encode('utf-8') no effect.

[HandyGuySoftware]

So even without the 'utf-8' bit it still emails incorrectly but the file output is correct?

[dcurrey]

Yep, 8bit had no effect.

This might be unique to my server. For some reason the lines are getting a hard return at length 999 in the email source.

I even manually edited an email in the /var/vmail directory and removed the extra line returns combining them to 1 line. Guess what it worked.

The old 2.03 method seem to create much shorter lines

<html><head></head><body><table border=1 cellpadding="5"><tr><td bgcolor="#E6E6E6" align="center" colspan = "11"><b>Duplicati Backup Summary Report
</b></td></tr>
<tr><td align="right">Date       </td><td align="right">Time     </td><td align="right">     Files</td><td align="right">+/-       </td><td align="right">         Size (MB)</td><td align="right">+/- (MB)          </td><td align="right">     Added</td><td align="right">   Deleted</td><td align="right">  Modified</td><td align="right">    Errors</td><td align="right">Result     </td></tr>
<tr><td bgcolor="#E6E6E6" align="center" colspan = "11"><b>***** Xxxxxxx to xx *****</b></td></tr>
<tr><td align="center" colspan = "11"><i>No new activity. Last activity on 2017-11-17 at 20:00:16 (25 days ago)</i></td></tr>
<tr><td bgcolor="#E6E6E6" align="center" colspan = "11"><b>***** Xxxxxxxx to yy *****</b></td></tr>
<tr><td align="center" colspan = "11"><i>No new activity. Last activity on 2017-12-11 at 13:00:38 (1 days ago)</i></td></tr>
<tr><td bgcolor="#E6E6E6" align="center" colspan = "11"><b>***** Xxxxxxx to yy *****</b></td></tr>
<snip>

The closing /body and /html lines are missing however?

[dcurrey]

Success!

It seems lines longer than 1000 violates RFC 5321. Postfix was trying to enforce this by putting a line break in when processing the email.

Solution was to add a "\n" outside of the html code in reports.py and rpt_srcdest. I tried to find all the closting \tr and add it at that location. Of course this would have to be added to all the rpt_*,py code.

For example line 69 of rpt_srcdest.py now reads as

msgHtml += '<tr><td colspan="{}" align="center" bgcolor="{}"><b>{}:</b> {} <b>{}:</b> {}</td></tr>\n'.format(nFields, reportOpts['subheadbg'], rptTits['source'], source, \
                rptTits['destination'], destination)

This is the same report from above

<html><head></head><body><table border=1 cellpadding="5"><tr><td align="center" colspan="13" bgcolor="#FFFFFF"><b>Duplicati Backup Summary Report</b></td></tr>
<tr><td align="left">Date</td><td align="left">Time</td><td align="right">Files</td><td align="right">+/-</td><td align="right">Size</td><td align="right">+/-</td><td align="right">Added</td><td align="right">Deleted</td><td align="right">Modified</td><td align="right">Errors</td><td align="left">Result</td></tr>
<tr><td colspan="13" align="center" bgcolor="#D3D3D3"><b>Source:</b> backup <b>Destination:</b> ddc3</td></tr>
<tr><td align="left">11/02/2017</td><td align="left">17:38:10</td><td align="right">           7</td><td align="right">          +7</td><td align="right">              48,992</td><td align="right">             +48,992</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr>
<tr><td align="left">11/02/2017</td><td align="left">17:40:11</td><td align="right">          12</td><td align="right">          +5</td><td align="right">           6,935,285</td><td align="right">          +6,886,293</td><td align="right">           5</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr>
<tr><td align="left">11/02/2017</td><td align="left">18:06:39</td><td align="right">          12</td><td align="right">          +0</td><td align="right">           6,935,285</td><td align="right">                  +0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr>
<tr><td align="left">11/22/2017</td><td align="left">13:59:19</td><td align="right">          56</td><td align="right">         +44</td><td align="right">          30,166,651</td><td align="right">         +23,231,366</td><td align="right">          44</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr>
<tr><td align="left">12/12/2017</td><td align="left">16:02:30</td><td align="right">          50</td><td align="right">          -6</td><td align="right">             606,609</td><td align="right">         -29,560,042</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr>
<tr><td align="left">12/12/2017</td><td align="left">16:20:47</td><td align="right">          50</td><td align="right">          +0</td><td align="right">             606,609</td><td align="right">                  +0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="right">           0</td><td align="left">Success</td></tr>
<tr><td align="left">12/12/2017</td><td align="left">16:22:53</td><td align="right">          50</td><td align="right">          +0</td><td align="right">             606,624</td><td align="right">                 +15</td><td align="right">           0</td><td align="right">           0</td><td align="right">           1</td><td align="right">           0</td><td align="left">Success</td></tr>
<tr><td colspan=13 align="center"><b>Running Time: 0.285 seconds.</b></td></tr></table></body></html>

[HandyGuySoftware]

Fascinating. As I'm thinking about it, having all the white space in the fields is needed for the text version of the message, but HTML and CSV both ignore white space. Between the leading spaces and the additional HTML tags in 2.1, I bet that's what helped send it over the edge in length. I should reconsider the formatting for the HTML and CSV messages.

In any case, that's an easy fix. Thanks for tracking that down. I'll try to update the code tonight.

BTW, I also finally fixed the showdisplay bugs in the .rc file. The program should now both correctly convert old .rc files and create new ones without crashing. Hopefully.

[HandyGuySoftware]

OK, fix made and pushed. Please check if this fixes the issue once and for all. (Keeping fingers crossed)

[dcurrey]

Found one! Not really related to this.

If you have warnoncollect = true in the rc file. It fails to process the warnings unless you run with the -c option.

Possible fix is dremail.py line 414.

if ((globs.opts['collect'] is True) or not globs.opts['report']) and (globs.opts['warnoncollect'] is True) and ((statusParts['warnings'] != '') or (statusParts['errors'] != '')):

Other than that everything looks good. :)

[HandyGuySoftware]

The original logic there is good. This came from Issue #20 ,

"I am not alerted to any errors in between the -c and when I run dupreport with the -t option. "

So my understanding of the requirement is that you only want to be alerted if you are running under -c and an incoming email has an error/warning. If you are running under -t or without either -c/-t the program will generate errors/warnings normally, as they both end in a report (or file) generation.

In pseudo-code:

if (-c collecting only)
----if (warnoncollect)
--------if (warning != "" or error != "")
------------send warning/error email
--------else
------------do nothing
----else
--------do nothing
else (using -t or neither option)
----Analyze incoming emails and produce report email

In the fix you propose, you would produce the warn/error email if either running under -t or neither, potentially producing multiple emails for a single report run, as in:

if (-c collecting only)
----if (warnoncollect)
--------if (warning != "" or error != "")
------------send warning/error email
--------else
------------do nothing
----else
--------do nothing
else (using -t or neither option)
----if (warnoncollect)
--------if (warning != "" or error != "")
------------send email with warning/error
--------else
------------do nothing
----else
--------do nothing
----Analyze incoming emails and produce report email

Did I misinterpret the requirement?

[dcurrey]

No you got it right.

Don't know what I was doing or thinking last night that I thought a change was needed here Guess I shouldn't hurry up and run some test before bedtime. :)

Sorry about that.

[HandyGuySoftware]

No worries. Many of the bugs I've thought were fixed but subsequently you found not to be were the result of working too fast & too late :-)

I'm going to close this issue and move on to the next. Thanks for all your work on this.