Mailinabox: Backup status error after update to v22

[ma0ho]

I'm using rsync backup to my personal NAS. Unfortunately, after updating to v22, I see a "float division by zero" error on opening the backup status page. I seems to happen while the list of backups is loaded. This list actually isn't displayed anymore. I receive the same error as part of the nightly backup status mail.

Maybe I can do some more investigation later this week..

[yodax]

Could you run management/backup.py status from the cli?

[tynie]

Exactly same problem here. Running ./backup.py status gives same error:

root@box:~/mailinabox/management# ./backup.py status
float division by zero
root@box:~/mailinabox/management#

[yodax]

First thing that comes to mind is this line here: https://github.com/mail-in-a-box/mailinabox/blob/master/management/backup.py#L121

We check incremental_count, but not incremental_size. So if that's zero it will fail. We could add a check for that here

[yodax]

Could you test this branch in my repo? https://github.com/yodax/mailinabox/tree/backupfix

[tynie]

Just copied your backup.py to my /management folder and ran ./backup.py status
But i didn´t got any return:

root@box:~/mailinabox/management# ./backup.py status
root@box:~/mailinabox/management#

The Backup Tab shows same error: "float division by zero"

[rainulf]

I can confirm this issue shows up as well after upgrading to v22.

[yodax]

Putting in the file isn't enough for the site. You need to run the setup of the management interface.

[tynie]

Okay i think that worked. But filesize is 0 Bytes.

[yodax]

Ok it seems that the underlying problem is that the incremental file size isn't calculated properly. What backup type are you using?

[tynie]

I´m using rsync to backup the files to my second vserver. Do you think disable backup - save all backups to my local PC - and enable the backup function would work?

[yodax]

Could you run this bit manually and post the output?

rsync_command = [ 'rsync',
                    '-e',
                    '/usr/bin/ssh -i /root/.ssh/id_rsa_miab -oStrictHostKeyChecking=no -oBatchMode=yes',
                    '--list-only',
                    '-r',
                    rsync_target.format(
                        host=target.netloc,
                        path=target_path)
                ]

From bash it would be

rsync -e /usr/bin/ssh -i /root/.ssh/id_rsa_miab -o StrictHostKeyChecking=no -oBatchMode=yes --list-only -r remote:/path

Where remote:/path is the destination host.

[tynie]

Wrong syntax:

root@box:~# rsync -e /usr/bin/ssh -i /root/.ssh/id_rsa_miab -o StrictHostKeyChecking=no -oBatchMode=yes --list-only -r remote:/media/Storage_sdb1/http_backup/mail-in-a-box
rsync: -oBatchMode=yes: invalid numeric value
rsync error: syntax or usage error (code 1) at main.c(1572) [client=3.1.0]

Running without that command gives:

root@box:~# rsync -e /usr/bin/ssh -i /root/.ssh/id_rsa_miab -o StrictHostKeyChecking=no --list-only -r myhost.net:/media/Storage_sdb1/http_backup/mail-in-a-box
[email protected]´s password:
rsync: link_stat "/root/StrictHostKeyChecking=no" failed: No such file or directory (2)
-rw-------          1,679 2017/02/22 16:37:07 id_rsa_miab
rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1183) [sender=3.1.0]

[yodax]

This needs to go as well: -o StrictHostKeyChecking=no

[yodax]

Paging @guyzmo, could you have a look at this?

@JoshData this branch handles the error more gracefully but doesn't offer a in-depth fix. I think it is wise to included so it will never divide by zero again. What do you think? The diff:

-   if incremental_count > 0 and first_full_size is not None:
+   if incremental_count > 0 and incremental_size > 0 and first_full_size is not None:

[durd]

+1

[yodax]

Can anyone else try and run the command line? It's crashing because we can't parse the output. Since I don't have access to a box with the error I can't reproduce the problem without that information.

[sa7lej]

root@jonsson:~# rsync -e /usr/bin/ssh -i /root/.ssh/id_rsa_miab  --list-only -r user@host:/home/azral/Backup/mail
user@hosts's password:
-rw-------          1,675 2016/12/01 13:41:39 id_rsa_miab

Something like that, then?

[yodax]

No I think I made a mistake, thanks for trying though! Could you try this:

rsync -e "/usr/bin/ssh -i /root/.ssh/id_rsa_miab -o StrictHostKeyChecking=no -oBatchMode=yes" --list-only -r remote:/path

[sa7lej]

Thats more like it!

root@jonsson:~# rsync -e "/usr/bin/ssh -i /root/.ssh/id_rsa_miab -o StrictHostKeyChecking=no -oBatchMode=yes" --list-only -r user@hostname:/home/azral/Backup/mail
drwxrwxr-x          4,096 2017/04/03 03:00:41 mail
-rw-------     62,642,099 2017/03/26 03:10:29 mail/duplicity-full-signatures.20170326T010009Z.sigtar.gpg
-rw-------            897 2017/03/26 03:10:34 mail/duplicity-full.20170326T010009Z.manifest.gpg
-rw-------    262,160,327 2017/03/26 03:01:30 mail/duplicity-full.20170326T010009Z.vol1.difftar.gpg
-rw-------    154,459,875 2017/03/26 03:10:14 mail/duplicity-full.20170326T010009Z.vol10.difftar.gpg
-rw-------    262,172,576 2017/03/26 03:02:42 mail/duplicity-full.20170326T010009Z.vol2.difftar.gpg
-rw-------    262,174,186 2017/03/26 03:03:42 mail/duplicity-full.20170326T010009Z.vol3.difftar.gpg
-rw-------    262,164,707 2017/03/26 03:04:39 mail/duplicity-full.20170326T010009Z.vol4.difftar.gpg
-rw-------    262,159,493 2017/03/26 03:05:44 mail/duplicity-full.20170326T010009Z.vol5.difftar.gpg
-rw-------    262,162,706 2017/03/26 03:06:47 mail/duplicity-full.20170326T010009Z.vol6.difftar.gpg
-rw-------    262,169,839 2017/03/26 03:07:40 mail/duplicity-full.20170326T010009Z.vol7.difftar.gpg
-rw-------    262,166,469 2017/03/26 03:08:33 mail/duplicity-full.20170326T010009Z.vol8.difftar.gpg
-rw-------    262,168,045 2017/03/26 03:09:30 mail/duplicity-full.20170326T010009Z.vol9.difftar.gpg
-rw-------            339 2017/03/27 03:02:35 mail/duplicity-inc.20170326T010009Z.to.20170327T010009Z.manifest.gpg
-rw-------    262,147,033 2017/03/27 03:01:26 mail/duplicity-inc.20170326T010009Z.to.20170327T010009Z.vol1.difftar.gpg
-rw-------    132,448,763 2017/03/27 03:02:26 mail/duplicity-inc.20170326T010009Z.to.20170327T010009Z.vol2.difftar.gpg
-rw-------            238 2017/03/28 03:00:51 mail/duplicity-inc.20170327T010009Z.to.20170328T010004Z.manifest.gpg
-rw-------     49,577,746 2017/03/28 03:00:49 mail/duplicity-inc.20170327T010009Z.to.20170328T010004Z.vol1.difftar.gpg
-rw-------            235 2017/03/29 03:00:41 mail/duplicity-inc.20170328T010004Z.to.20170329T010004Z.manifest.gpg
-rw-------      6,134,368 2017/03/29 03:00:39 mail/duplicity-inc.20170328T010004Z.to.20170329T010004Z.vol1.difftar.gpg
-rw-------            239 2017/03/30 03:00:42 mail/duplicity-inc.20170329T010004Z.to.20170330T010009Z.manifest.gpg
-rw-------      4,081,908 2017/03/30 03:00:40 mail/duplicity-inc.20170329T010004Z.to.20170330T010009Z.vol1.difftar.gpg
-rw-------            237 2017/03/31 03:00:42 mail/duplicity-inc.20170330T010009Z.to.20170331T010010Z.manifest.gpg
-rw-------      2,973,619 2017/03/31 03:00:41 mail/duplicity-inc.20170330T010009Z.to.20170331T010010Z.vol1.difftar.gpg
-rw-------            240 2017/04/01 03:00:41 mail/duplicity-inc.20170331T010010Z.to.20170401T010009Z.manifest.gpg
-rw-------      4,023,439 2017/04/01 03:00:38 mail/duplicity-inc.20170331T010010Z.to.20170401T010009Z.vol1.difftar.gpg
-rw-------            234 2017/04/02 03:00:41 mail/duplicity-inc.20170401T010009Z.to.20170402T010009Z.manifest.gpg
-rw-------      3,298,462 2017/04/02 03:00:40 mail/duplicity-inc.20170401T010009Z.to.20170402T010009Z.vol1.difftar.gpg
-rw-------            241 2017/04/03 03:00:41 mail/duplicity-inc.20170402T010009Z.to.20170403T010009Z.manifest.gpg
-rw-------      3,652,768 2017/04/03 03:00:40 mail/duplicity-inc.20170402T010009Z.to.20170403T010009Z.vol1.difftar.gpg
-rw-------     24,183,291 2017/03/27 03:02:32 mail/duplicity-new-signatures.20170326T010009Z.to.20170327T010009Z.sigtar.gpg
-rw-------        958,214 2017/03/28 03:00:50 mail/duplicity-new-signatures.20170327T010009Z.to.20170328T010004Z.sigtar.gpg
-rw-------        549,629 2017/03/29 03:00:40 mail/duplicity-new-signatures.20170328T010004Z.to.20170329T010004Z.sigtar.gpg
-rw-------        512,574 2017/03/30 03:00:41 mail/duplicity-new-signatures.20170329T010004Z.to.20170330T010009Z.sigtar.gpg
-rw-------        401,055 2017/03/31 03:00:41 mail/duplicity-new-signatures.20170330T010009Z.to.20170331T010010Z.sigtar.gpg
-rw-------        517,206 2017/04/01 03:00:39 mail/duplicity-new-signatures.20170331T010010Z.to.20170401T010009Z.sigtar.gpg
-rw-------        468,019 2017/04/02 03:00:41 mail/duplicity-new-signatures.20170401T010009Z.to.20170402T010009Z.sigtar.gpg
-rw-------        494,516 2017/04/03 03:00:40 mail/duplicity-new-signatures.20170402T010009Z.to.20170403T010009Z.sigtar.gpg

[tynie]

yes same here:

root@box:~# rsync -e "/usr/bin/ssh -i /root/.ssh/id_rsa_miab -o StrictHostKeyChecking=no -oBatchMode=yes" --list-only -r [email protected]:/media/Storage_sdb1/http_backup/mail-in-a-box
drwxr-xr-x         16,384 2017/04/04 03:00:56 mail-in-a-box
-rw-------     10,136,753 2017/04/04 03:00:48 mail-in-a-box/duplicity-full-signatures.20170404T010025Z.sigtar.gpg
-rw-------            236 2017/04/04 03:00:49 mail-in-a-box/duplicity-full.20170404T010025Z.manifest.gpg
-rw-------    258,837,715 2017/04/04 03:00:45 mail-in-a-box/duplicity-full.20170404T010025Z.vol1.difftar.gpg

Sorry for that late reply

[ma0ho]

Yes, I can. But it just tells "float division by zero" as well :(..
Nothing else. I'd guess it is some time-out-problem, because MIAB needs
to connect to my local NAS, which might take some time. But before the
update it worked regardless of the delay.

time sudo ./backup.py
float division by zero

real 0m14.884s
user 0m0.291s
sys 0m0.081s

On Mon, Apr 3, 2017 at 10:18 AM, Michael Kroes
[e-mail] wrote:

Could you run management/backup.py status from the cli?

—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub, or mute the thread.

[yodax]

Thanks for the results. I have tested the regex on those results and that should work. I don't see anything that is obviously wrong or release related. This will need some more digging. I need to think about this some more.

[durd]

Late to the party, but as the others (except for ma0ho), the rsync-command works :)

[ma0ho]

I'll check this evening ;)

On Tue, Apr 4, 2017 at 6:07 PM, David [e-mail] wrote:

Late to the party, but as the others (except for ma0ho), the
rsync-command works :)

—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub, or mute the thread.

[netsound]

All three of my upgraded instances to .22 are failing with the same " invalid literal for int() with base 10: 'WARNING:' " error when trying to backup to the rsync share. Heck even trying to browse to the backup tab in the web admin the same error is thrown.

[yodax]

I've setup a test environment and created an rsync backup to another machine. Everything works. When I run the results posted here through the regex, all is fine. No changes have been made to the code in the .22 release. I'm not sure what else I can try to reproduce this.

[durd]

@yodax
Is it a clean .22-installation that you are testing on? A scenario is that this issue comes from updating from earlier versions. I installed miab at version .20 for instance and went over to official rsync-backups as soon as it was available, i was running rsync through cron earlier.

[yodax]

It was an upgraded install. It previously had rsync on it. It was reconfigured after .22 was released.

[durd]

Ok, had to ask as it wasn't clear :)

Well, i managed to fix my miab.
On the remote site where backups are rsynced to:
rm -rf duplicity-*

Ran backup.py status and boom, a full backup and no division by zero. Everytime i run backup.py status a new incremental is created and rsynced. Edit: webgui is fine aswell.
Not the best workaround though.

I ran the upgrade for 0.22 again before that if that is a clue.

[tynie]

Worked for me too @durd - no error while running backup.py - but webgui doesn´t shows "Size" and "Deleted in...". Do you have that problem, too?

[durd]

@tynie Nope, ive got "Size" and "Deleted in...".

[yodax]

@tynie I'm not sure how fast your uplink is or how large the dataset, but 2 minutes for the backup seems fast.

@durd could you run this command as well so we can see if there is a difference?

rsync -e "/usr/bin/ssh -i /root/.ssh/id_rsa_miab -o StrictHostKeyChecking=no -oBatchMode=yes" --list-only -r remote:/path

[sa7lej]

I erased all files on my backupserver and waited overnight for the backup to run again. The backup seems to work but in the gui it shows this result:

If i run the command i'l get this result:

root@jonsson:~# rsync -e "/usr/bin/ssh -i /root/.ssh/id_rsa_miab -o StrictHostKeyChecking=no -oBatchMode=yes" --list-only -r user@hostname:/home/azral/Backup/mail/
drwxrwxr-x 4,096 2017/04/06 03:11:07 .
-rw------- 65,571,023 2017/04/06 03:11:01 duplicity-full-signatures.20170406T010010Z.sigtar.gpg
-rw------- 890 2017/04/06 03:11:07 duplicity-full.20170406T010010Z.manifest.gpg
-rw------- 262,157,538 2017/04/06 03:01:27 duplicity-full.20170406T010010Z.vol1.difftar.gpg
-rw------- 222,975,653 2017/04/06 03:10:48 duplicity-full.20170406T010010Z.vol10.difftar.gpg
-rw------- 262,172,968 2017/04/06 03:02:38 duplicity-full.20170406T010010Z.vol2.difftar.gpg
-rw------- 262,174,121 2017/04/06 03:03:38 duplicity-full.20170406T010010Z.vol3.difftar.gpg
-rw------- 262,172,538 2017/04/06 03:04:35 duplicity-full.20170406T010010Z.vol4.difftar.gpg
-rw------- 262,169,121 2017/04/06 03:05:37 duplicity-full.20170406T010010Z.vol5.difftar.gpg
-rw------- 262,172,512 2017/04/06 03:06:46 duplicity-full.20170406T010010Z.vol6.difftar.gpg
-rw------- 262,166,625 2017/04/06 03:07:43 duplicity-full.20170406T010010Z.vol7.difftar.gpg
-rw------- 262,165,083 2017/04/06 03:08:35 duplicity-full.20170406T010010Z.vol8.difftar.gpg
-rw------- 262,177,063 2017/04/06 03:09:30 duplicity-full.20170406T010010Z.vol9.difftar.gpg

[tynie]

@yodax My backup is about 100MB and bandwidth is about 200Mbit/s so i think that is realistic.
@azzeman Same problem here!

[ma0ho]

I also deleted the backup files and waited overnight. I see the same
result as @azzeman.

[durd]

@yodax I mentioned this in an earlier comment, but yes, the command works.
But before running the upgrade again (not sure what impact that would have had) and removing the backups, the webgui and backup status-emails had the error float division by zero as OP has/had.

All: I realize this is a bit late, I should have mentioned this earlier.
_Please_ be _careful_ with your backups. They are backups for a reason!
I removed them because I only use miab to relay mail, not store anything!

[yodax]

I suspected it would work. The command is used to calculate the file size and the backups present. So I wanted to compare a "failed" listing with a "working" listing. On my test machine it did count the size.

[durd]

No problem, let me know if you want me to try anything else. I'll still be following this issue.

[sa7lej]

And on day 2- i'm back on the "float division by zero"-error again.

[tynie]

@azzeman same here

[ma0ho]

Same for me :-(

Am 7. Apr. 2017, 12:15, um 12:15, tynie [e-mail] schrieb:

@azzeman same here

--
You are receiving this because you authored the thread.
Reply to this email directly or view it on GitHub:
https://github.com/mail-in-a-box/mailinabox/issues/1132#issuecomment-292499025

[yodax]

Would somebody be so kind and rerun the setup for me? I'm suspecting an upstream issue. Also to explain the silence. I've been busy but I suspect I can reproduce this maybe tomorrow.

[sa7lej]

I have just been running the setup again (with the same result) - do you want me to look for something special?

[yodax]

If it still fails it didn't help. I'm still unable to reproduce it. My testbox is happily using rsync backup for two days now.

If prepared a new version of backup.py on gist. It contains a few print statements. [deleted gist]

Could someone backup there original backup.py and replace it with this one. Then run:

management/backup.py --list

And post the output here. (If you want you can sanitise the hostname etc, I care about the file sizes and the parsed lines)

[sa7lej]

root@jonsson:~/mailinabox/management# ./backup.py --list
Rsync command:
['rsync', '-e', '/usr/bin/ssh -i /root/.ssh/id_rsa_miab -oStrictHostKeyChecking=no -oBatchMode=yes', '--list-only', '-r', 'user@hostname:/home/azral/Backup/mail']

Listing:
drwxrwxr-x          4,096 2017/04/07 03:00:40 mail
-rw-------     65,571,023 2017/04/06 03:11:01 mail/duplicity-full-signatures.20170406T010010Z.sigtar.gpg
-rw-------            890 2017/04/06 03:11:07 mail/duplicity-full.20170406T010010Z.manifest.gpg
-rw-------    262,157,538 2017/04/06 03:01:27 mail/duplicity-full.20170406T010010Z.vol1.difftar.gpg
-rw-------    222,975,653 2017/04/06 03:10:48 mail/duplicity-full.20170406T010010Z.vol10.difftar.gpg
-rw-------    262,172,968 2017/04/06 03:02:38 mail/duplicity-full.20170406T010010Z.vol2.difftar.gpg
-rw-------    262,174,121 2017/04/06 03:03:38 mail/duplicity-full.20170406T010010Z.vol3.difftar.gpg
-rw-------    262,172,538 2017/04/06 03:04:35 mail/duplicity-full.20170406T010010Z.vol4.difftar.gpg
-rw-------    262,169,121 2017/04/06 03:05:37 mail/duplicity-full.20170406T010010Z.vol5.difftar.gpg
-rw-------    262,172,512 2017/04/06 03:06:46 mail/duplicity-full.20170406T010010Z.vol6.difftar.gpg
-rw-------    262,166,625 2017/04/06 03:07:43 mail/duplicity-full.20170406T010010Z.vol7.difftar.gpg
-rw-------    262,165,083 2017/04/06 03:08:35 mail/duplicity-full.20170406T010010Z.vol8.difftar.gpg
-rw-------    262,177,063 2017/04/06 03:09:30 mail/duplicity-full.20170406T010010Z.vol9.difftar.gpg
-rw-------            236 2017/04/07 03:00:40 mail/duplicity-inc.20170406T010010Z.to.20170407T010009Z.manifest.gpg
-rw-------      3,080,802 2017/04/07 03:00:38 mail/duplicity-inc.20170406T010010Z.to.20170407T010009Z.vol1.difftar.gpg
-rw-------        408,169 2017/04/07 03:00:39 mail/duplicity-new-signatures.20170406T010010Z.to.20170407T010009Z.sigtar.gpg


Return:
[('mail', 4096), ('mail/duplicity-full-signatures.20170406T010010Z.sigtar.gpg', 65571023), ('mail/duplicity-full.20170406T010010Z.manifest.gpg', 890), ('mail/duplicity-full.20170406T010010Z.vol1.difftar.gpg', 262157538), ('mail/duplicity-full.20170406T010010Z.vol10.difftar.gpg', 222975653), ('mail/duplicity-full.20170406T010010Z.vol2.difftar.gpg', 262172968), ('mail/duplicity-full.20170406T010010Z.vol3.difftar.gpg', 262174121), ('mail/duplicity-full.20170406T010010Z.vol4.difftar.gpg', 262172538), ('mail/duplicity-full.20170406T010010Z.vol5.difftar.gpg', 262169121), ('mail/duplicity-full.20170406T010010Z.vol6.difftar.gpg', 262172512), ('mail/duplicity-full.20170406T010010Z.vol7.difftar.gpg', 262166625), ('mail/duplicity-full.20170406T010010Z.vol8.difftar.gpg', 262165083), ('mail/duplicity-full.20170406T010010Z.vol9.difftar.gpg', 262177063), ('mail/duplicity-inc.20170406T010010Z.to.20170407T010009Z.manifest.gpg', 236), ('mail/duplicity-inc.20170406T010010Z.to.20170407T010009Z.vol1.difftar.gpg', 3080802), ('mail/duplicity-new-signatures.20170406T010010Z.to.20170407T010009Z.sigtar.gpg', 408169)]
mail    4096
mail/duplicity-full-signatures.20170406T010010Z.sigtar.gpg      65571023
mail/duplicity-full.20170406T010010Z.manifest.gpg       890
mail/duplicity-full.20170406T010010Z.vol1.difftar.gpg   262157538
mail/duplicity-full.20170406T010010Z.vol10.difftar.gpg  222975653
mail/duplicity-full.20170406T010010Z.vol2.difftar.gpg   262172968
mail/duplicity-full.20170406T010010Z.vol3.difftar.gpg   262174121
mail/duplicity-full.20170406T010010Z.vol4.difftar.gpg   262172538
mail/duplicity-full.20170406T010010Z.vol5.difftar.gpg   262169121
mail/duplicity-full.20170406T010010Z.vol6.difftar.gpg   262172512
mail/duplicity-full.20170406T010010Z.vol7.difftar.gpg   262166625
mail/duplicity-full.20170406T010010Z.vol8.difftar.gpg   262165083
mail/duplicity-full.20170406T010010Z.vol9.difftar.gpg   262177063
mail/duplicity-inc.20170406T010010Z.to.20170407T010009Z.manifest.gpg    236
mail/duplicity-inc.20170406T010010Z.to.20170407T010009Z.vol1.difftar.gpg        3080802
mail/duplicity-new-signatures.20170406T010010Z.to.20170407T010009Z.sigtar.gpg   408169
root@jonsson:~/mailinabox/management#

[yodax]

@azzeman thanks!

Can you check if you have a / at the end of the path in the UI? I do and if I remove it I get the same error as you do.

[yodax]

I've fixed it on my test machine when I was able to reproduce it. I've created a PR for it here.

If anyone would care to test if it also fixes it for you, that would be great and much appreciated!

[sa7lej]

Ah!

It works when i have an ending /

Great work!

[tynie]

Works! Thank you!

[ma0ho]

Works!

On Mon, Apr 10, 2017 at 7:08 PM, tynie [e-mail] wrote:

Works! Thank you!

—
You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub, or mute the thread.

[hachre]

I had the issue as well and can confirm that the given backup.py in the PR fixed it for me as well. Thanks! My installation was a brand new v22 install btw. It started happening after the first incremental backup had finished.

[JoshData]

I've merged the PR so I'm closing this issue. Thanks all.